From owner-freebsd-i386@FreeBSD.ORG Wed Sep 20 21:57:03 2006 Return-Path: X-Original-To: freebsd-i386@freebsd.org Delivered-To: freebsd-i386@freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id CE15A16A40F; Wed, 20 Sep 2006 21:57:03 +0000 (UTC) (envelope-from jdc@koitsu.dyndns.org) Received: from sccrmhc12.comcast.net (sccrmhc12.comcast.net [204.127.200.82]) by mx1.FreeBSD.org (Postfix) with ESMTP id 37A6043D45; Wed, 20 Sep 2006 21:57:03 +0000 (GMT) (envelope-from jdc@koitsu.dyndns.org) Received: from icarus.home.lan (c-24-6-182-130.hsd1.ca.comcast.net[24.6.182.130]) by comcast.net (sccrmhc12) with ESMTP id <20060920215701012002djp9e>; Wed, 20 Sep 2006 21:57:01 +0000 Received: by icarus.home.lan (Postfix, from userid 1000) id 36C521FA01A; Wed, 20 Sep 2006 14:57:01 -0700 (PDT) Date: Wed, 20 Sep 2006 14:57:01 -0700 From: Jeremy Chadwick To: FreeBSD-gnats-submit@FreeBSD.org, freebsd-i386@FreeBSD.org Message-ID: <20060920215701.GA1257@icarus.home.lan> References: <20060920160651.C79AC1FA035@icarus.home.lan> <200609201610.k8KGAUcT056271@freefall.freebsd.org> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <200609201610.k8KGAUcT056271@freefall.freebsd.org> X-PGP-Key: http://jdc.parodius.com/pubkey.asc User-Agent: Mutt/1.5.13 (2006-08-11) Cc: Subject: Re: i386/103435: Kernel appears somewhat deadlocked during heavy ATA I/O (post-August 4th) X-BeenThere: freebsd-i386@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: I386-specific issues for FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 20 Sep 2006 21:57:03 -0000 Follow-up: The PR I referenced has indeed now happened to me. This ultimately resulted in a hard system lock -- then the kernel panic'd in some UFS2 code. When I came home from work, I was able to play around a bit on the console of the box. Naturally I did "panic" to make a memory dump -- but it couldn't. It tried to write 1MB of the 1014MB (or so), and simply sat there doing nothing; disk LED wasn't even lit. When I brought the machine back up, I saw the following: Sep 20 14:48:19 icarus kernel: Trying to mount root from ufs:/dev/ad12s1a Sep 20 14:48:19 icarus kernel: WARNING: / was not properly dismounted Sep 20 14:48:19 icarus kernel: WARNING: /var was not properly dismounted Sep 20 14:48:19 icarus kernel: /var: mount pending error: blocks 4 files 1 Sep 20 14:48:19 icarus kernel: WARNING: /tmp was not properly dismounted Sep 20 14:48:19 icarus kernel: WARNING: /usr was not properly dismounted Sep 20 14:48:19 icarus kernel: WARNING: /home was not properly dismounted Sep 20 14:48:19 icarus kernel: /home: mount pending error: blocks 4 files 1 Sep 20 14:48:19 icarus kernel: WARNING: /storage/ad14 was not properly dismounted Sep 20 14:48:19 icarus savecore: no dumps found I was able to go through /var/log/messages to find all of this -- none of which bodes well for 6.2-RELEASE, if you ask me. Has anyone contacted Soren and/or Kris about this? Sep 20 14:48:19 icarus syslogd: kernel boot file is /boot/kernel/kernel Sep 20 14:48:19 icarus kernel: anged to UP Sep 20 14:48:19 icarus kernel: g_vfs_done():ad12s1g[WRITE(offset=56459116544, length=16384)]error = 5 Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES SET TRANSFER MODE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES SET TRANSFER MODE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES ENABLE RCACHE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES ENABLE WCACHE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SET_MULTI taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: TIMEOUT - WRITE_DMA retrying (1 retry left) LBA=287 Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES SET TRANSFER MODE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES SET TRANSFER MODE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES ENABLE RCACHE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES ENABLE WCACHE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SET_MULTI taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: TIMEOUT - WRITE_DMA retrying (1 retry left) LBA=524639 Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES SET TRANSFER MODE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES SET TRANSFER MODE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES ENABLE RCACHE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES ENABLE WCACHE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SET_MULTI taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: TIMEOUT - WRITE_DMA retrying (0 retries left) LBA=287 Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES SET TRANSFER MODE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES SET TRANSFER MODE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES ENABLE RCACHE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES ENABLE WCACHE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SET_MULTI taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: TIMEOUT - WRITE_DMA retrying (0 retries left) LBA=524639 Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES SET TRANSFER MODE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES SET TRANSFER MODE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES ENABLE RCACHE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES ENABLE WCACHE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SET_MULTI taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: FAILURE - WRITE_DMA timed out LBA=287 Sep 20 14:48:19 icarus kernel: g_vfs_done():ad12s1a[WRITE(offset=114688, length=16384)]error = 5 Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES SET TRANSFER MODE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES SET TRANSFER MODE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES ENABLE RCACHE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES ENABLE WCACHE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SET_MULTI taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: FAILURE - WRITE_DMA timed out LBA=524639 Sep 20 14:48:19 icarus kernel: g_vfs_done():ad12s1a[WRITE(offset=268582912, length=16384)]error = 5 {...and so on...} Sep 20 14:48:19 icarus kernel: em0: watchdog timeout -- resetting Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES ENABLE WCACHE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SET_MULTI taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: TIMEOUT - WRITE_DMA retrying (1 retry left) LBA=30998367 Sep 20 14:48:19 icarus kernel: em0: 2 link states coalesced Sep 20 14:48:19 icarus kernel: em0: link state changed to UP Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES SET TRANSFER MODE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES SET TRANSFER MODE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES ENABLE RCACHE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES ENABLE WCACHE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SET_MULTI taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: TIMEOUT - WRITE_DMA retrying (0 retries left) LBA=17837855 Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES SET TRANSFER MODE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES SET TRANSFER MODE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES ENABLE RCACHE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES ENABLE WCACHE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: em0: watchdog timeout -- resetting Sep 20 14:48:19 icarus kernel: ad12: WARNING - SET_MULTI taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: TIMEOUT - WRITE_DMA retrying (0 retries left) LBA=30998367 Sep 20 14:48:19 icarus kernel: em0: link state changed to DOWN Sep 20 14:48:19 icarus kernel: em0: link state changed to UP Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES SET TRANSFER MODE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES SET TRANSFER MODE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES ENABLE RCACHE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES ENABLE WCACHE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SET_MULTI taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: FAILURE - WRITE_DMA timed out LBA=17837855 Sep 20 14:48:19 icarus kernel: g_vfs_done():ad12s1d[WRITE(offset=6144000, length=2048)]error = 5 Sep 20 14:48:19 icarus kernel: em0: watchdog timeout -- resetting {...lots more...} Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES SET TRANSFER MODE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES SET TRANSFER MODE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES ENABLE RCACHE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SETFEATURES ENABLE WCACHE taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: WARNING - SET_MULTI taskqueue timeout - completing request directly Sep 20 14:48:19 icarus kernel: ad12: FAILURE - WRITE_DMA timed out LBA=41160159 Sep 20 14:48:19 icarus kernel: g_vfs_done():ad12s1d[WRITE(offset=11947163648, length=16384)]error = 5 Sep 20 14:48:19 icarus kernel: panic: initiate_write_inodeblock_ufs2: already started Sep 20 14:48:19 icarus kernel: KDB: enter: panic Sep 20 14:48:19 icarus kernel: panic: from debugger Sep 20 14:48:19 icarus kernel: Uptime: 2d5h35m17s Sep 20 14:48:19 icarus kernel: Dumping 1014 MB (2 chunks) Sep 20 14:48:19 icarus kernel: chunk 0: 1MB (159 pages) (CTRL-C to abort) (CTRL-C to abort) (CTRL-C to abort) (CTRL-C to abort) (CTRL-C to abort) Sep 20 14:48:19 icarus kernel: Dump aborted Sep 20 14:48:19 icarus kernel: Automatic reboot in 15 seconds - press a key on the console to abort Sep 20 14:48:19 icarus kernel: --> Press a key on the console to reboot, Sep 20 14:48:19 icarus kernel: --> or switch off the system now. Sep 20 14:48:19 icarus kernel: Rebooting... -- | Jeremy Chadwick jdc at parodius.com | | Parodius Networking http://www.parodius.com/ | | UNIX Systems Administrator Mountain View, CA, USA | | Making life hard for others since 1977. PGP: 4BD6C0CB |