From owner-freebsd-current@FreeBSD.ORG Tue Dec 11 21:55:59 2012 Return-Path: Delivered-To: freebsd-current@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [69.147.83.52]) by hub.freebsd.org (Postfix) with ESMTP id B74ADC5F; Tue, 11 Dec 2012 21:55:59 +0000 (UTC) (envelope-from rmacklem@uoguelph.ca) Received: from esa-annu.net.uoguelph.ca (esa-annu.mail.uoguelph.ca [131.104.91.36]) by mx1.freebsd.org (Postfix) with ESMTP id 2FDEB8FC17; Tue, 11 Dec 2012 21:55:58 +0000 (UTC) X-IronPort-Anti-Spam-Filtered: true X-IronPort-Anti-Spam-Result: AqAEAF6rx1CDaFvO/2dsb2JhbAA9CIY3uC9zgh4BAQEDAQEBASAEJyALGw4KAgINGQIpAQkmBggHBAEIFASHagYMqF+CQJBBgSKLKAsMBA2DCIETA4hginmCLoEcjyyDEYFIBxce X-IronPort-AV: E=Sophos;i="4.84,262,1355115600"; d="scan'208";a="4387206" Received: from erie.cs.uoguelph.ca (HELO zcs3.mail.uoguelph.ca) ([131.104.91.206]) by esa-annu.net.uoguelph.ca with ESMTP; 11 Dec 2012 16:55:52 -0500 Received: from zcs3.mail.uoguelph.ca (localhost.localdomain [127.0.0.1]) by zcs3.mail.uoguelph.ca (Postfix) with ESMTP id 22248B3EE4; Tue, 11 Dec 2012 16:55:52 -0500 (EST) Date: Tue, 11 Dec 2012 16:55:52 -0500 (EST) From: Rick Macklem To: Konstantin Belousov Message-ID: <1814631088.1331228.1355262952071.JavaMail.root@erie.cs.uoguelph.ca> In-Reply-To: <20121211045225.GY3013@kib.kiev.ua> Subject: Re: r244036 kernel hangs under load. MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-Originating-IP: [172.17.91.203] X-Mailer: Zimbra 6.0.10_GA_2692 (ZimbraWebClient - FF3.0 (Linux)/6.0.10_GA_2692) Cc: Tim Kientzle , freebsd-current Current X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.14 Precedence: list List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 11 Dec 2012 21:55:59 -0000 Konstantin Belousov wrote: > On Mon, Dec 10, 2012 at 07:11:59PM -0500, Rick Macklem wrote: > > Konstantin Belousov wrote: > > > On Mon, Dec 10, 2012 at 01:38:21PM -0500, Rick Macklem wrote: > > > > Adrian Chadd wrote: > > > > > .. what was the previous kernel version? > > > > > > > > > Hopefully Tim has it narrowed down more, but I don't see > > > > the hangs on a Sept. 7 kernel from head and I do see them > > > > on a Dec. 3 kernel from head. (Don't know the eact rNNNNNN.) > > > > > > > > It seems to predate my commit (r244008), which was my first > > > > concern. > > > > > > > > I use old single core i386 hardware and can fairly reliably > > > > reproduce it by doing a kernel build and a "svn checkout" > > > > concurrently. No NFS activity. These are running on a local > > > > disk (UFS/FFS). (The kernel I reproduce it on is built via > > > > GENERIC for i386. If you want me to start a "binary search" > > > > for which rNNNNNN, I can do that, but it will take a while.:-) > > > > > > > > I can get out into DDB, but I'll admit I don't know enough > > > > about it to know where to look;-) > > > > Here's some lines from "db> ps", in case they give someone > > > > useful information. (I can leave this box sitting in DB for > > > > the rest of to-day, in case someone can suggest what I should > > > > look for on it.) > > > > > > > > Just snippets... > > > > Ss pause adjkerntz > > > > DL sdflush [sofdepflush] > > > > RL [syncer] > > > > DL vlruwt [vnlru] > > > > DL psleep [bufdaemon] > > > > RL [pagezero] > > > > DL psleep [vmdaemon] > > > > DL psleep [pagedaemon] > > > > DL ccb_scan [xpt_thrd] > > > > DL waiting_ [sctp_iterator] > > > > DL ctl_work [ctl_thrd] > > > > DL cooling [acpi_cooling0] > > > > DL tzpoll [acpi_thermal] > > > > DL (threaded) [usb] > > > > ... > > > > DL - [yarrow] > > > > DL (threaded) [geom] > > > > D - [g_down] > > > > D - [g_up] > > > > D - [g_event] > > > > RL (threaded) [intr] > > > > I [irq15: ata1] > > > > ... > > > > Run CPU0 [swi6: Giant taskq] > > > > --> does this one indicate the CPU is actually running this? > > > > (after a db> cont, wait a while db> ps > > > > it is still the same) > > > > I [swi4: clock] > > > > I [swi1: netisr 0] > > > > I [swi3: vm] > > > > RL [idle: cpu0] > > > > SLs wait [init] > > > > DL audit_wo [audit] > > > > DLs (threaded) [kernel] > > > > D - [deadlkres] > > > > ... > > > > D sched [swapper] > > > > > > > > I have no idea if this "ps" output helps, unless it indicates > > > > that it is looping on the Giant taskq? > > > Might be. You could do 'bt ' for the process to see where it > > > loops. > > > Another good set of hints is at > > > http://www.freebsd.org/doc/en_US.ISO8859-1/books/developers-handbook/kerneldebug-deadlocks.html > > > > Kostik, you must be clairvoyant;-) > > > > When I did "show alllocks", I found that the syncer process held > > - exclusive sleep mutex mount mtx locked @ kern/vfs_subr.c:4720 > > - exclusive lockmgr syncer locked @ kern/vfs_subr.c:1780 > > The trace for this process goes like: > > spinlock_exit > > mtx_unlock_spin_flags > > kern_yield > > _mnt_vnode_next_active > > vnode_next_active > > vfs_msync() > > > > So, it seems like your r244095 commit might have fixed this? > > (I'm not good at this stuff, but from your description, it looks > > like it did the kern_yield() with the mutex held and "maybe" > > got into trouble trying to acquire Giant?) > > > > Anyhow, I'm going to test a kernel with r244095 in it and see > > if I can still reproduce the hang. > > (There wasn't much else in the "show alllocks", except a > > process that held the exclusive vnode interlock mutex plus > > a ufs vnode lock, but it's just doing a witness_unlock.) > There must be a thread blocked for the mount interlock for the loop > in the mnt_vnode_next_active to cause livelock. > Yes. I am getting hangs with the -current kernel and they seem easier for me to reproduce. For the one I just did, the "syncer" seems to be blocked at VI_TRYLOCK() in _mnt_vnode_next_active(). The vnode interlock mutex is eclusively locked by a "sh" process (11627). Now, here is where it gets weird... When I do a "db> trace 11627" I get the following: witness_unlock+0x1f3 (subr_witness.c:1563) mtx_unlock_flags+0x9f (kern_mutex.c:250) vdropl+0x63 (vfs_subr.c:2405) vputx+0x130 (vfs_subr.c:2116) vput+0x10 (vfs_subr.c:2319) vm_mmap+0x52e (vm_mmap.c:1341) sys_mmap So, it seems this process is stuck while trying to unlock the mutex, if that makes any sense... When I look at subr_witness.c around 1563, I can't see why anything would block there? (here's the code snippet) if ((instance->li_flags & LI_EXCLUSIVE) == 0 && witness_watch > 0 && (flags & LOP_EXCLUSIVE) != 0) { printf("exclusive unlock of (%s) %s @ %s:%d\n", class->lc_name, lock->lo_name, fixup_filename(file), line); printf("while share locked from %s:%d\n", fixup_filename(instance->li_file), instance->li_line); panic("share->uexcl"); } /* If we are recursed, unrecurse. */ *1563* if ((instance->li_flags & LI_RECURSEMASK) > 0) { CTR4(KTR_WITNESS, "%s: pid %d unrecursed on %s r=%d", __func__, td->td_proc->p_pid, instance->li_lock->lo_name, instance->li_flags); instance->li_flags--; return; } /* The lock is now being dropped, check for NORELEASE flag */ if ((instance->li_flags & LI_NORELEASE) != 0 && witness_watch > 0) { printf("forbidden unlock of (%s) %s @ %s:%d\n", class->lc_name, lock->lo_name, fixup_filename(file), line); So, what is really going on is still a mystery to me. (I do see interrupt stuff on the "bt"'s from the debugger, if that means anything?) rick > > > > I'll email if/when I know more, rick > > ps: Fingers/toes crossed that you've already fixed it. > > > > > > > > > > > > > As I said, I can leave it in "db" for to-day, if anyone wants > > > > me to do anything in the debugger and I can probably reproduce > > > > it, if someone wants stuff tried later. > > > > > > > > rick > > > > > > > > > > > > > > > > > > > > > > > adrian > > > > > > > > > > > > > > > On 9 December 2012 22:08, Tim Kientzle > > > > > wrote: > > > > > > I haven't found any useful clues yet, but thought I'd ask if > > > > > > anyone > > > > > > else > > > > > > was seeing hangs in a recent kernel. > > > > > > > > > > > > I just upgraded to r244036 using a straight GENERIC i386 > > > > > > kernel. > > > > > > (Straight buildworld/buildkernel, no local changes, > > > > > > /etc/src.conf > > > > > > doesn't > > > > > > exist, /etc/make.conf just has PERL_VERSION defined.) > > > > > > > > > > > > When I try to cross build an ARM world on the resulting > > > > > > system, > > > > > > the entire system hangs hard after about 30 minutes: No > > > > > > network, > > > > > > no keyboard response, no nothing. > > > > > > > > > > > > Don't know if it's relevant, but the system is using NFS > > > > > > pretty > > > > > > heavily (Parallels VM mounting NFS from Mac OS 10.7 host.) > > > > > > > > > > > > I'll try to get some more details ... > > > > > > > > > > > > Tim > > > > > > > > > > > > _______________________________________________ > > > > > > freebsd-current@freebsd.org mailing list > > > > > > http://lists.freebsd.org/mailman/listinfo/freebsd-current > > > > > > To unsubscribe, send any mail to > > > > > > "freebsd-current-unsubscribe@freebsd.org" > > > > > _______________________________________________ > > > > > freebsd-current@freebsd.org mailing list > > > > > http://lists.freebsd.org/mailman/listinfo/freebsd-current > > > > > To unsubscribe, send any mail to > > > > > "freebsd-current-unsubscribe@freebsd.org" > > > > _______________________________________________ > > > > freebsd-current@freebsd.org mailing list > > > > http://lists.freebsd.org/mailman/listinfo/freebsd-current > > > > To unsubscribe, send any mail to > > > > "freebsd-current-unsubscribe@freebsd.org"