Crash dump in umount

Tue Apr 15 03:44:25 PDT 2003

** Reply to note from "Greg 'groggy' Lehey" <grog at FreeBSD.org> 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.