From owner-freebsd-stable@FreeBSD.ORG Tue Apr 15 03:44:24 2003 Return-Path: Delivered-To: freebsd-stable@freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id B000437B401 for ; Tue, 15 Apr 2003 03:44:24 -0700 (PDT) Received: from smtp1.libero.it (smtp1.libero.it [193.70.192.51]) by mx1.FreeBSD.org (Postfix) with ESMTP id C04A743F75 for ; Tue, 15 Apr 2003 03:44:22 -0700 (PDT) (envelope-from ml.ventu@flashnet.it) Received: from soth.ventu (151.42.126.110) by smtp1.libero.it (7.0.012) id 3E954686001AA09A for freebsd-stable@FreeBSD.org; Tue, 15 Apr 2003 12:44:21 +0200 Received: from mailer (xanatar.ventu [10.1.2.6]) by soth.ventu (8.12.6p2/8.12.6) with SMTP id h3FAiLQF001834 for ; Tue, 15 Apr 2003 12:44:21 +0200 (CEST) (envelope-from ml.ventu@flashnet.it) Message-Id: <200304151044.h3FAiLQF001834@soth.ventu> To: freebsd-stable@FreeBSD.org Priority: Normal X-Mailer: Post Road Mailer for OS/2 (Green Edition Ver 3.0) Date: Tue, 15 Apr 2003 12:44:21 EST From: Andrea Venturoli Subject: Re: Crash dump in umount X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.1 Precedence: list Reply-To: Andrea Venturoli List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 15 Apr 2003 10:44:25 -0000 ** Reply to note from "Greg 'groggy' Lehey" Tue, 15 Apr 2003 17:18:59 +0930 First of all, thanks a lot!!! > Is this a Vinum volume? Yes, it might really be: my / is obviously not, but /usr and /var are two mirrored vinum volumes, so this is very probable. > > And, finally, this is my kernel configuration file: > > Despite what some documentation says, this is seldom useful. Ok, I'll forget about it. > If this is Vinum (as I strongly suspect), it's probably a known (but > hard to reproduce) bug. Take a look at > http://www.vinumvm.org/vinum/how-to-debug.html and check in particular > that you have the symbols for frames 7 to 9. Also, in this case, > knowing exactly the circumstances would be of great assistance. This > includes the history and log files, but if you have other information, > it would be good. Ok. I'll start over and I'll try to do what is possible, but I'm afraid, since the crash happened a long time ago, I can't provide everything. The problem I had is a kernel panic while doing "shutdown now", so as to go from multi-user to single-user mode on a FreeBSD-4.7 machine (don't remenber the patch level, but it has changed almost for sure, since then). I'm not posting the panic message again, since I already did (but I can, if you want). I have made no modification to the sources. vinum list gives: >4 drives: >D drive0 State: up Device /dev/da0s1e Avail: 0/8119 MB (0%) >D drive1 State: up Device /dev/da1s1e Avail: 0/8119 MB (0%) >D vinumdrive0 State: up Device /dev/da2s1e Avail: 0/34815 MB (0%) >D vinumdrive1 State: up Device /dev/da3s1e Avail: 0/34815 MB (0%) > >2 volumes: >V mirror State: up Plexes: 2 Size: 8119 MB >V vinum0 State: up Plexes: 2 Size: 33 GB > >4 plexes: >P mirror.p0 C State: up Subdisks: 1 Size: 8119 MB >P mirror.p1 C State: up Subdisks: 1 Size: 8119 MB >P vinum0.p0 C State: up Subdisks: 1 Size: 33 GB >P vinum0.p1 C State: up Subdisks: 1 Size: 33 GB > >4 subdisks: >S mirror.p0.s0 State: up PO: 0 B Size: 8119 MB >S mirror.p1.s0 State: up PO: 0 B Size: 8119 MB >S vinum0.p0.s0 State: up PO: 0 B Size: 33 GB >S vinum0.p1.s0 State: up PO: 0 B Size: 33 GB Vinum history is harder, since I've had this crash a few times and I can't really track the first one down to a specific period, however, I'll post a portion that shows how I added the second mirror (the first one was there since the machine was built, more than two years ago): 14 Feb 2003 10:34:31.920341 *** vinum started *** 14 Feb 2003 10:34:31.922954 stop 14 Feb 2003 10:34:42.863915 *** vinum started *** 14 Feb 2003 10:34:42.864382 stop 14 Feb 2003 10:45:22.910320 *** vinum started *** 14 Feb 2003 10:45:24.338641 hrlp 14 Feb 2003 10:45:25.345697 help 14 Feb 2003 10:45:44.754887 l 14 Feb 2003 10:46:08.805548 *** vinum started *** 14 Feb 2003 10:46:48.925969 *** vinum started *** 14 Feb 2003 10:47:12.130783 mirror /dev/da2e /dev/da3e 14 Feb 2003 10:47:56.707978 mirror -v /dev/da2e /dev/da3e 14 Feb 2003 10:50:01.551391 *** vinum started *** 14 Feb 2003 10:50:20.922330 mirror -v /dev/da2s1e /dev/da3s1e 14 Feb 2003 10:51:05.315153 *** vinum started *** 14 Feb 2003 10:51:16.765716 mirror -v /dev/da2e /dev/da3e 14 Feb 2003 10:51:32.558758 l 14 Feb 2003 10:51:39.059748 l|less 14 Feb 2003 10:51:39.783584 q 14 Feb 2003 10:51:42.377530 *** vinum started *** 14 Feb 2003 10:51:42.378002 l 14 Feb 2003 10:51:43.937899 *** vinum started *** 14 Feb 2003 10:51:43.938365 l 14 Feb 2003 10:52:13.815260 *** vinum started *** 14 Feb 2003 10:52:13.815741 l 14 Feb 2003 10:52:39.537335 *** vinum started *** 14 Feb 2003 10:52:53.195358 rm vinumdrive2 14 Feb 2003 10:52:54.480422 l 14 Feb 2003 10:52:55.810177 l 14 Feb 2003 10:52:56.374773 l 14 Feb 2003 10:52:59.324123 rm vinumdrive2 14 Feb 2003 10:53:19.937628 detach vinumdrive2 14 Feb 2003 10:53:29.151924 ld 14 Feb 2003 10:53:38.379483 makedev 14 Feb 2003 10:53:38.379561 *** Created devices *** 14 Feb 2003 10:53:40.504766 l 14 Feb 2003 10:53:45.564409 rm vinumdrive2 14 Feb 2003 10:53:49.989253 rm -v vinumdrive2 14 Feb 2003 10:53:51.409654 l 14 Feb 2003 10:53:55.781018 l 14 Feb 2003 10:54:03.018641 *** vinum started *** 14 Feb 2003 10:54:03.581842 l 14 Feb 2003 10:54:10.740564 start vinum0 14 Feb 2003 10:54:12.185792 l 14 Feb 2003 10:54:14.715417 l 14 Feb 2003 10:57:17.657208 *** vinum started *** 14 Feb 2003 10:57:18.100727 l 14 Feb 2003 10:57:31.280756 rm vinum0 14 Feb 2003 10:57:39.443846 rm vinum0.p0.s0 14 Feb 2003 10:57:45.174619 *** vinum started *** 14 Feb 2003 10:57:45.737931 l 14 Feb 2003 10:58:12.900269 rm vinumdrive0 14 Feb 2003 10:58:13.802356 ls 14 Feb 2003 10:58:14.606860 l 14 Feb 2003 10:58:15.910870 l 14 Feb 2003 10:58:24.908422 stop vinum0 14 Feb 2003 10:58:25.793626 l 14 Feb 2003 10:58:29.980583 rm vinum0 14 Feb 2003 10:58:31.386100 l 14 Feb 2003 10:58:36.316076 stop vinum0.p0 14 Feb 2003 10:58:37.829926 stop vinum0.p0.s0 14 Feb 2003 10:58:39.653687 stop vinum0.p1 14 Feb 2003 10:58:41.491287 stop vinum0.p1.s0 14 Feb 2003 10:58:42.315956 l 14 Feb 2003 10:58:51.640633 stop vinum0.p1 14 Feb 2003 10:58:53.586683 l 14 Feb 2003 10:58:55.643426 stop vinum0.p1.s0 14 Feb 2003 10:58:56.528608 l 14 Feb 2003 10:59:01.138560 rm vinum0.p0 14 Feb 2003 10:59:02.997780 rm vinum0.p0.s0 14 Feb 2003 10:59:04.728030 l 14 Feb 2003 11:04:21.553647 *** vinum started *** 14 Feb 2003 11:04:21.560594 dumpconfig 14 Feb 2003 11:04:27.016584 *** vinum started *** 14 Feb 2003 11:04:27.017022 dumpconfig vc 14 Feb 2003 11:05:15.411678 *** vinum started *** 14 Feb 2003 11:05:18.381594 dumpconfig vc 14 Feb 2003 11:05:25.221262 *** vinum started *** 14 Feb 2003 11:05:25.221722 dumpconfig 14 Feb 2003 11:05:36.665076 *** vinum started *** 14 Feb 2003 11:05:36.665482 start 14 Feb 2003 11:05:36.768317 *** Created devices *** 14 Feb 2003 11:13:28.236670 *** vinum started *** 14 Feb 2003 11:13:28.640196 l 14 Feb 2003 11:14:45.889868 l 14 Feb 2003 11:42:05.515988 *** vinum started *** 14 Feb 2003 11:42:06.703809 l 14 Feb 2003 12:12:19.621359 *** vinum started *** 14 Feb 2003 12:12:19.901781 l 14 Feb 2003 12:13:00.739358 *** vinum started *** 14 Feb 2003 12:13:03.353809 l 14 Feb 2003 12:13:06.538648 start mirror 14 Feb 2003 12:13:10.838106 start mirror.p1 14 Feb 2003 12:13:12.167668 l 14 Feb 2003 12:13:23.958799 start mirror.p1.s0 14 Feb 2003 12:14:45.013518 l 14 Feb 2003 12:14:50.259459 start mirror.p1.s0 14 Feb 2003 12:15:06.267699 start mirror.p1 14 Feb 2003 12:15:08.979258 l 14 Feb 2003 12:15:12.328147 help start 14 Feb 2003 13:25:39.306817 *** vinum started *** 14 Feb 2003 13:25:39.794973 l 14 Feb 2003 13:27:03.165315 *** vinum started *** 14 Feb 2003 13:27:03.928615 l 14 Feb 2003 13:27:46.260087 create # Vinum configuration of xxx.yyy.zz, saved at Fri Feb 14 13:27:46 2003 # Current configuration: # drive drive0 device /dev/da0s1e # drive drive1 device /dev/da1s1e drive vinumdrive0 device /dev/da2s1e drive vinumdrive1 device /dev/da3s1e # volume mirror # volume vinum0 # plex name mirror.p0 org concat vol mirror # plex name mirror.p1 org concat vol mirror # plex name vinum0.p0 org concat vol vinum0 # plex name vinum0.p1 org concat vol vinum0 # sd name mirror.p0.s0 drive drive0 plex mirror.p0 len 16628000s driveoffset 265 s plexoffset 0s # sd name mirror.p1.s0 drive drive1 plex mirror.p1 len 16628000s driveoffset 265 s plexoffset 0s # sd name vinum0.p0.s0 drive vinumdrive0 plex vinum0.p0 len 0s driveoffset 36028 797018963967s plexoffset 0s # sd name vinum0.p1.s0 drive vinumdrive1 plex vinum0.p1 len 0s driveoffset 36028 797018963967s plexoffset 0s 14 Feb 2003 13:28:11.100777 *** Created devices *** 14 Feb 2003 13:28:53.786699 start vinum0 14 Feb 2003 13:29:27.246159 ls -v 14 Feb 2003 13:29:37.783749 l 14 Feb 2003 13:29:56.773130 setstate obsolete mirror.p1.s0 14 Feb 2003 13:29:57.822926 l 14 Feb 2003 13:30:06.754179 setstate obsolete mirror.p1 14 Feb 2003 13:30:08.320881 l 14 Feb 2003 13:30:11.291587 start mirror 14 Feb 2003 13:30:15.654944 start mirror.p1 14 Feb 2003 13:30:21.831391 l 14 Feb 2003 13:31:13.928725 l 14 Feb 2003 13:32:24.391396 vinum start vinum0.p0 14 Feb 2003 13:32:27.870392 start vinum0.p0 14 Feb 2003 13:32:31.919900 l 14 Feb 2003 13:32:36.686116 l .. /pages of "l" and "*** vinum started ***" omitted 14 Feb 2003 13:51:26.273945 *** vinum started *** 14 Feb 2003 13:51:26.274462 l 14 Feb 2003 13:30:15.654944 start mirror.p1 14 Feb 2003 13:52:15.737073 *** vinum started *** 14 Feb 2003 13:52:15.737563 l .. /pages of "l" and "*** vinum started ***" omitted 14 Feb 2003 14:47:38.176066 *** vinum started *** 14 Feb 2003 14:47:38.176566 ls -v 14 Feb 2003 13:32:27.870392 start vinum0.p0 14 Feb 2003 14:48:31.454147 *** vinum started *** 14 Feb 2003 14:48:31.454662 ls -v 14 Feb 2003 14:48:33.446896 *** vinum started *** 14 Feb 2003 14:48:33.447403 ls -v 14 Feb 2003 14:48:36.591026 *** vinum started *** 14 Feb 2003 14:48:36.994180 l 14 Feb 2003 15:02:08.449527 *** vinum started *** 14 Feb 2003 15:02:08.450035 l 14 Feb 2003 15:09:20.206456 *** vinum started *** 14 Feb 2003 15:09:20.219947 start 14 Feb 2003 15:09:20.416385 *** Created devices *** 14 Feb 2003 16:03:35.512446 *** vinum started *** 14 Feb 2003 16:03:35.541576 l 14 Feb 2003 16:32:04.379424 *** vinum started *** 14 Feb 2003 16:32:04.397705 l 14 Feb 2003 16:32:45.675942 *** vinum started *** 14 Feb 2003 16:32:45.731253 start vinum0.p1 14 Feb 2003 16:32:51.700621 *** vinum started *** 14 Feb 2003 16:32:51.701102 l 14 Feb 2003 16:37:55.055038 *** vinum started *** 14 Feb 2003 16:37:55.058900 l 14 Feb 2003 16:32:45.731253 start vinum0.p1 14 Feb 2003 17:58:23.553250 *** vinum started *** 14 Feb 2003 17:58:23.553755 l 17 Feb 2003 16:28:31.452568 *** vinum started *** 17 Feb 2003 16:28:31.480844 l 25 Feb 2003 18:38:26.060442 *** vinum started *** 25 Feb 2003 18:38:26.071646 start 25 Feb 2003 18:38:26.245734 *** Created devices *** 25 Feb 2003 18:48:26.391711 *** vinum started *** 25 Feb 2003 18:48:26.399283 start 25 Feb 2003 18:48:26.570335 *** Created devices *** 27 Feb 2003 13:17:34.733384 *** vinum started *** 27 Feb 2003 13:17:34.761988 l 27 Feb 2003 13:17:42.059448 *** vinum started *** 27 Feb 2003 13:17:42.059934 start mirror.p1 27 Feb 2003 13:31:34.506558 *** vinum started *** 27 Feb 2003 13:31:34.507087 l 27 Feb 2003 13:17:42.059934 start mirror.p1 27 Feb 2003 13:35:22.612829 *** vinum started *** etc... Unfortunately I cannot provide an extract of /var/log/messages, since it's long gone :( In case I get another crash of this kind, I will. This is the output of bt: (kgdb) bt #0 dumpsys () at ../../kern/kern_shutdown.c:487 #1 0xc015b2ef in boot (howto=0x104) at ../../kern/kern_shutdown.c:316 #2 0xc015b714 in poweroff_wait (junk=0xc02594cc, howto=0xc0258fef) at ../../kern/kern_shutdown.c:595 #3 0xc021c30a in trap_fatal (frame=0xc82c7a48, eva=0x2c) at ../../i386/i386/trap.c:974 #4 0xc021bfdd in trap_pfault (frame=0xc82c7a48, usermode=0x0, eva=0x2c) at ../../i386/i386/trap.c:867 #5 0xc021bbc7 in trap (frame={tf_fs = 0x10, tf_es = 0x10, tf_ds = 0x10, tf_edi = 0xc0cef800, tf_esi = 0x1, tf_ebp = 0xc82c7a88, tf_isp = 0xc82c7a74, tf_ebx = 0xc0cdfe20, tf_edx = 0x2, tf_ecx = 0x1, tf_eax = 0x0, tf_trapno = 0xc, tf_err = 0x0, tf_eip = 0xc014f4ea, tf_cs = 0x8, tf_eflags = 0x10246, tf_esp = 0xc82c7aa8, tf_ss = 0xc0adb7f1}) at ../../i386/i386/trap.c:466 #6 0xc014f4ea in devsw (dev=0x0) at ../../kern/kern_conf.c:76 #7 0xc0adb7f1 in launch_requests (rq=0xc0c02440, reviveok=0x0) at /usr/src/sys/modules/vinum/../../dev/vinum/vinumrequest.c:433 #8 0xc0adb4ea in vinumstart (bp=0xc33b7840, reviveok=0x0) at /usr/src/sys/modules/vinum/../../dev/vinum/vinumrequest.c:291 #9 0xc0adb352 in vinumstrategy (bp=0xc33b7840) at /usr/src/sys/modules/vinum/../../dev/vinum/vinumrequest.c:164 #10 0xc0193f48 in spec_strategy (ap=0xc82c7b2c) at ../../miscfs/specfs/spec_vnops.c:479 #11 0xc0193971 in spec_vnoperate (ap=0xc82c7b2c) at ../../miscfs/specfs/spec_vnops.c:119 #12 0xc01dc955 in ufs_vnoperatespec (ap=0xc82c7b2c) at ../../ufs/ufs/ufs_vnops.c:2440 #13 0xc0180bfa in bwrite (bp=0xc33c24bc) at vnode_if.h:944 #14 0xc018620e in vop_stdbwrite (ap=0xc82c7b74) at ../../kern/vfs_default.c:331 #15 0xc0186069 in vop_defaultop (ap=0xc82c7b74) at ../../kern/vfs_default.c:150 #16 0xc0193971 in spec_vnoperate (ap=0xc82c7b74) at ../../miscfs/specfs/spec_vnops.c:119 #17 0xc01dc955 in ufs_vnoperatespec (ap=0xc82c7b74) at ../../ufs/ufs/ufs_vnops.c:2440 #18 0xc0180f4a in bawrite (bp=0xc33c24bc) at vnode_if.h:1193 #19 0xc01d1baa in softdep_fsync_mountdev (vp=0xc841c640) at ../../ufs/ffs/ffs_softdep.c:4048 #20 0xc01d5d12 in ffs_fsync (ap=0xc82c7bfc) at ../../ufs/ffs/ffs_vnops.c:134 #21 0xc01d49a3 in ffs_sync (mp=0xc0b9ae00, waitfor=0x2, cred=0xc0731900, p=0xc02b94e0) at vnode_if.h:558 #22 0xc018b0df in sync (p=0xc02b94e0, uap=0x0) at ../../kern/vfs_syscalls.c:576 #23 0xc015b08a in boot (howto=0x100) at ../../kern/kern_shutdown.c:235 #24 0xc015b714 in poweroff_wait (junk=0xc02594cc, howto=0xc0258fef) at ../../kern/kern_shutdown.c:595 #25 0xc021c30a in trap_fatal (frame=0xc82c7d1c, eva=0x2c) at ../../i386/i386/trap.c:974 #26 0xc021bfdd in trap_pfault (frame=0xc82c7d1c, usermode=0x0, eva=0x2c) at ../../i386/i386/trap.c:867 #27 0xc021bbc7 in trap (frame={tf_fs = 0x10, tf_es = 0x10, tf_ds = 0x10, tf_edi = 0xc0cc6c00, tf_esi = 0x1, tf_ebp = 0xc82c7d5c, tf_isp = 0xc82c7d48, tf_ebx = 0xc0bb4020, tf_edx = 0x1, tf_ecx = 0x1, tf_eax = 0x0, tf_trapno = 0xc, tf_err = 0x0, tf_eip = 0xc014f4ea, tf_cs = 0x8, tf_eflags = 0x10246, tf_esp = 0xc82c7d7c, tf_ss = 0xc0adb7f1}) at ../../i386/i386/trap.c:466 #28 0xc014f4ea in devsw (dev=0x0) at ../../kern/kern_conf.c:76 #29 0xc0adb7f1 in launch_requests (rq=0xc0c023c0, reviveok=0x0) at /usr/src/sys/modules/vinum/../../dev/vinum/vinumrequest.c:433 #30 0xc0adb4ea in vinumstart (bp=0xc33a4cac, reviveok=0x0) at /usr/src/sys/modules/vinum/../../dev/vinum/vinumrequest.c:291 #31 0xc0adb352 in vinumstrategy (bp=0xc33a4cac) at /usr/src/sys/modules/vinum/../../dev/vinum/vinumrequest.c:164 #32 0xc0193f48 in spec_strategy (ap=0xc82c7dfc) at ../../miscfs/specfs/spec_vnops.c:479 #33 0xc0193971 in spec_vnoperate (ap=0xc82c7dfc) at ../../miscfs/specfs/spec_vnops.c:119 #34 0xc01dc955 in ufs_vnoperatespec (ap=0xc82c7dfc) at ../../ufs/ufs/ufs_vnops.c:2440 #35 0xc01dc255 in ufs_strategy (ap=0xc82c7e40) at vnode_if.h:944 #36 0xc01dc925 in ufs_vnoperate (ap=0xc82c7e40) at ../../ufs/ufs/ufs_vnops.c:2422 #37 0xc0180bfa in bwrite (bp=0xc33a4cac) at vnode_if.h:944 #38 0xc018620e in vop_stdbwrite (ap=0xc82c7e7c) at ../../kern/vfs_default.c:331 #39 0xc0186069 in vop_defaultop (ap=0xc82c7e7c) at ../../kern/vfs_default.c:150 #40 0xc01dc925 in ufs_vnoperate (ap=0xc82c7e7c) at ../../ufs/ufs/ufs_vnops.c:2422 #41 0xc0180f4a in bawrite (bp=0xc33a4cac) at vnode_if.h:1193 #42 0xc01d5e9e in ffs_fsync (ap=0xc82c7ee8) at ../../ufs/ffs/ffs_vnops.c:198 #43 0xc01d48cb in ffs_sync (mp=0xc0b9ae00, waitfor=0x2, cred=0xc0731900, p=0xc7801700) at vnode_if.h:558 #44 0xc018b0df in sync (p=0xc7801700, uap=0xc82c7f80) at ../../kern/vfs_syscalls.c:576 #45 0xc021c5b9 in syscall2 (frame={tf_fs = 0x2f, tf_es = 0x2f, tf_ds = 0x2f, tf_edi = 0x2, tf_esi = 0xbfbffde4, tf_ebp = 0xbfbffd90, tf_isp = 0xc82c7fd4, tf_ebx = 0xbfbffde4, tf_edx = 0x0, tf_ecx = 0x0, tf_eax = 0x24, tf_trapno = 0xc, tf_err = 0x2, tf_eip = 0x804a78c, tf_cs = 0x1f, tf_eflags = 0x292, tf_esp = 0xbfbffd54, tf_ss = 0x2f}) at ../../i386/i386/trap.c:1175 #46 0xc02109b5 in Xint0x80_syscall () #47 0x8048135 in ?? () This time, after I followed the instruction at http://www.vinumvm.org/vinum/how-to-debug.html, all frames have symbols; however I don't get 'Debugger ("vinum debug");' as descrived there. This might be because I've made minor upgrades in the meantime (from 4.7p? to 4.7p9) and recompiled, or because I get > .gdbinit:4: Error in sourced command file: > Cannot access memory at address 0x14. when I invoke gdb -k kernel.debug, or again for reasons that are unknown to me. Since I don't know whether this is fatal or not, I posted this anyway. Again, thank you very much for your interest and your help. bye av.