Date: Wed, 20 Sep 2006 22:00:48 GMT From: Jeremy Chadwick <freebsd@jdc.parodius.com> To: freebsd-i386@FreeBSD.org Subject: Re: i386/103435: Kernel appears somewhat deadlocked during heavy ATA I/O (post-August 4th) Message-ID: <200609202200.k8KM0mm0086165@freefall.freebsd.org>
next in thread | raw e-mail | index | archive | help
The following reply was made to PR i386/103435; it has been noted by GNATS.
From: Jeremy Chadwick <freebsd@jdc.parodius.com>
To: FreeBSD-gnats-submit@FreeBSD.org, freebsd-i386@FreeBSD.org
Cc:
Subject: Re: i386/103435: Kernel appears somewhat deadlocked during heavy ATA I/O (post-August 4th)
Date: Wed, 20 Sep 2006 14:57:01 -0700
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 |
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?200609202200.k8KM0mm0086165>