Date: Thu, 22 Feb 2001 00:33:23 -0500 From: "James F. Hranicky" <jfh@cise.ufl.edu> To: freebsd-fs@freebsd.org Subject: Re: Softupdates umount bug? Or vinum problem? Message-ID: <20010222053323.631B4DCD9@mail.cise.ufl.edu> In-Reply-To: Message from "James F. Hranicky" <jfh@cise.ufl.edu> of "Wed, 21 Feb 2001 09:03:26 EST." <20010221140326.8AF89D80A@mail.cise.ufl.edu>
next in thread | previous in thread | raw e-mail | index | archive | help
I stress tested a new fs for about 4 hours, creating and removing
100,000+ files at a time, and all went well until I tried to add
a larger plex to the vinum volume. This time, I got a crash in
the vinum routines:
db> trace
dscheck(c6f70e20,c7cc0500) at dscheck+0x104
diskstrategy(c6f70e20,c705c880,c7058800,cc1918b0,c796bd80) at diskstrategy+0x7d
launch_requests(c796bd80,0,cc1918b0,d70adec0,0) at launch_requests+0x2f7
vinumstart(cc1918b0,0,cc1918b0,d7106c68,c01d2b14) at vinumstart+0x1ce
vinumstrategy(cc1918b0,c7064680,d7106ce0,cc1918b0,d7106c74) at vinumstrategy+0x96
spec_strategy(d7106c98,d7106c80,c02b6ced,d7106c98,d7106ca4) at spec_strategy+0x8c
spec_vnoperate(d7106c98,d7106ca4,c01bf77e,d7106c98,c7cbe700) at spec_vnoperate+0x15
ufs_vnoperatespec(d7106c98) at ufs_vnoperatespec+0x15
bread(d70adec0,1a0040,2000,0,d7106ce0) at bread+0x8e
ffs_vget(c7fa0c00,61e80,d7106d58,0,d7310d40) at ffs_vget+0x1ce
ufs_lookup(d7106db0,d7106dc4,c01c32be,d7106db0,d7310d40) at ufs_lookup+0x9ad
ufs_vnoperate(d7106db0,d7310d40,d6eee01b,d7106eac,d79ea440) at ufs_vnoperate+0x15
vfs_cache_lookup(d7106e08,d7106e18,c01c6084,d7106e08,d5a5be00) at vfs_cache_lookup+0x28a
ufs_vnoperate(d7106e08,d5a5be00,d6eee000,d7106eac,d6e57ea0) at ufs_vnoperate+0x15
lookup(d7106e84,d6e57ea0,2,d6e57ea0,d6e57ea0) at lookup+0x290
namei(d7106e84,d6e57ea0,2,d7106f80,807d540) at namei+0x178
lstat(d6e57ea0,d7106f80,807d55c,807b000,807d500) at lstat+0x41
syscall2(2f,2f,2f,807d500,807b000) at syscall2+0x1f1
Xint0x80_syscall() at Xint0x80_syscall+0x25
db> c
Fatal trap 12: page fault while in kernel mode
fault virtual address = 0x3a32ca5b
fault code = supervisor read, page not present
instruction pointer = 0x8:0xc01a5818
stack pointer = 0x10:0xd7106bcc
frame pointer = 0x10:0xd7106be0
code segment = base 0x0, limit 0xfffff, type 0x1b
= DPL 0, pres 1, def32 1, gran 1
processor eflags = interrupt enabled, resume, IOPL = 0
current process = 24383 (rm)
interrupt mask = none
kernel: type 12 trap, code=0
Stopped at dscheck+0x104: movl 0xb8(%esi),%edx
db> c
I wasn't able to continue, so I couldn't get a dump.
Here's (hopefully) the relevant info:
- FreeBSD-STABLE 2/15
- vinum list (prior to the addition of the plex):
<root@dogwood:~> # vinum list
4 drives:
D d1 State: down Device /dev/da1s1e Avail: 0/35000 MB (0%)
D d2 State: down Device /dev/da2s1e Avail: 35000/35000 MB (100%)
D d3 State: down Device /dev/da3s1e Avail: 0/35000 MB (0%)
D d4 State: down Device /dev/da4s1e Avail: 0/35000 MB (0%)
1 volumes:
V mail State: up Plexes: 2 Size: 68 GB
2 plexes:
P mail.p0 C State: up Subdisks: 1 Size: 34 GB
P mail.p1 S State: up Subdisks: 2 Size: 68 GB
3 subdisks:
S mail.p0.s0 State: up PO: 0 B Size: 34 GB
S mail.p1.s0 State: up PO: 0 B Size: 34 GB
S mail.p1.s1 State: up PO: 256 kB Size: 34 GB
- vinum history excerpt
21 Feb 2001 15:42:55.860262 *** vinum started ***
21 Feb 2001 15:42:55.887197 start
21 Feb 2001 15:42:56.295117 *** Created devices ***
21 Feb 2001 15:43:49.435252 *** vinum started ***
21 Feb 2001 15:43:49.435719 start
21 Feb 2001 15:45:33.081283 *** vinum started ***
21 Feb 2001 15:45:33.081784 list
21 Feb 2001 15:46:04.679306 *** vinum started ***
21 Feb 2001 15:46:04.679796 stop mail.p1
21 Feb 2001 15:46:09.565558 *** vinum started ***
21 Feb 2001 15:46:09.566115 rm -rf mail.p1
21 Feb 2001 15:46:11.084216 *** vinum started ***
21 Feb 2001 15:46:11.084728 list
[ softupdates test runs during this time, no problems ]
21 Feb 2001 19:00:40.873656 *** vinum started ***
21 Feb 2001 19:00:40.910968 list
21 Feb 2001 19:01:00.353893 *** vinum started ***
21 Feb 2001 19:01:00.354407 create -f /tmp/mail.p1
drive d1 device /dev/da1s1e
drive d2 device /dev/da2s1e
drive d3 device /dev/da3s1e
drive d4 device /dev/da4s1e
plex name mail.p1 org striped 256k
sd name mail.p1.s0 length 0g drive d3
sd name mail.p1.s1 length 0g drive d4
21 Feb 2001 19:01:00.362798 *** Created devices ***
21 Feb 2001 19:01:45.423633 *** vinum started ***
21 Feb 2001 19:01:45.451875 attach mail.p1 mail
21 Feb 2001 19:01:49.437425 *** vinum started ***
21 Feb 2001 19:01:49.438050 list
21 Feb 2001 19:01:56.013097 *** vinum started ***
21 Feb 2001 19:01:56.017289 start mail.p1
21 Feb 2001 19:02:21.175751 *** vinum started ***
21 Feb 2001 19:02:21.191962 rm -rf mail.p1
21 Feb 2001 19:02:24.727802 *** vinum started ***
21 Feb 2001 19:02:24.728401 list
21 Feb 2001 19:02:29.647423 *** vinum started ***
21 Feb 2001 19:02:29.647976 list
21 Feb 2001 19:02:54.096393 *** vinum started ***
21 Feb 2001 19:02:54.118180 create -f /tmp/mail.p1
drive d1 device /dev/da1s1e
drive d2 device /dev/da2s1e
drive d3 device /dev/da3s1e
drive d4 device /dev/da4s1e
plex name mail.p1 org striped 256k
sd name mail.p1.s0 length 0g drive d3
sd name mail.p1.s1 length 0g drive d4
21 Feb 2001 19:02:54.124947 *** Created devices ***
21 Feb 2001 19:02:58.361927 *** vinum started ***
21 Feb 2001 19:02:58.362543 attach
21 Feb 2001 19:03:10.799338 *** vinum started ***
21 Feb 2001 19:03:10.803315 attach mail.p1 mail
21 Feb 2001 19:03:13.595055 *** vinum started ***
21 Feb 2001 19:03:13.595758 list
21 Feb 2001 19:03:25.612261 *** vinum started ***
21 Feb 2001 19:03:25.628535 start mail.p1
21 Feb 2001 19:03:29.242104 *** vinum started ***
21 Feb 2001 19:03:29.242695 start mail.p1.s0
21 Feb 2001 19:04:38.466545 *** vinum started ***
21 Feb 2001 19:04:38.470618 info
21 Feb 2001 19:04:41.256836 *** vinum started ***
21 Feb 2001 19:04:41.257616 list
21 Feb 2001 19:04:44.347045 *** vinum started ***
21 Feb 2001 19:04:44.347707 list -V
[ crash ]
21 Feb 2001 20:25:27.714923 *** vinum started ***
21 Feb 2001 20:25:27.723779 start
21 Feb 2001 20:26:56.869531 *** vinum started ***
21 Feb 2001 20:26:56.877844 list
21 Feb 2001 20:27:05.500935 *** vinum started ***
21 Feb 2001 20:27:05.501432 list
21 Feb 2001 20:27:23.784211 *** vinum started ***
21 Feb 2001 20:27:23.784716 stop mail.p1
21 Feb 2001 20:27:51.053214 *** vinum started ***
21 Feb 2001 20:27:51.053726 rm -rf mail.p1
21 Feb 2001 20:27:53.015977 *** vinum started ***
21 Feb 2001 20:27:53.016477 list
21 Feb 2001 20:34:51.023524 *** vinum started ***
21 Feb 2001 20:34:51.024037 list
21 Feb 2001 20:35:29.883130 *** vinum started ***
21 Feb 2001 20:35:29.883651 start d1
21 Feb 2001 20:35:32.740364 *** vinum started ***
21 Feb 2001 20:35:32.740895 list
21 Feb 2001 20:35:37.722339 *** vinum started ***
21 Feb 2001 20:35:37.722839 start d2
21 Feb 2001 20:35:38.772824 *** vinum started ***
21 Feb 2001 20:35:38.773334 start d3
21 Feb 2001 20:35:39.739196 *** vinum started ***
21 Feb 2001 20:35:39.739699 start d3=4
21 Feb 2001 20:35:42.224147 *** vinum started ***
21 Feb 2001 20:35:42.224650 start d4
21 Feb 2001 20:35:45.687607 *** vinum started ***
21 Feb 2001 20:35:45.688110 list
21 Feb 2001 20:42:34.205088 *** vinum started ***
21 Feb 2001 20:42:34.205594 list
21 Feb 2001 20:44:13.507914 *** vinum started ***
21 Feb 2001 20:44:13.508425 list -V
21 Feb 2001 20:44:55.647243 *** vinum started ***
21 Feb 2001 20:44:55.647759 read
21 Feb 2001 20:44:59.402924 *** vinum started ***
21 Feb 2001 20:44:59.403434 read da1
21 Feb 2001 20:45:04.688342 *** vinum started ***
21 Feb 2001 20:45:04.688846 read da1s1
21 Feb 2001 20:45:08.132045 *** vinum started ***
21 Feb 2001 20:45:08.132575 read /dev/da1s1
21 Feb 2001 20:45:12.547624 *** vinum started ***
21 Feb 2001 20:45:12.548132 read /dev/da1s1e
21 Feb 2001 20:45:12.640094 *** Created devices ***
21 Feb 2001 20:45:17.569063 *** vinum started ***
21 Feb 2001 20:45:17.569575 read /dev/da2s1e
21 Feb 2001 20:45:21.030786 *** vinum started ***
21 Feb 2001 20:45:21.031301 read /dev/da3s1e
[
I think it was with one of these commands I managed to get
/dev/da1s1e to show up like so:
D d1 State: down Device /dev/da1s1es1a Avail: 35000/35000 MB (100%)
Also, all of my vinum drives were marked down, and I had to bring them up
again by hand.
]
- messages
Feb 21 19:01:20 dogwood /kernel: vinum: mail.p1.s0 is up
Feb 21 19:01:20 dogwood /kernel: vinum: mail.p1.s1 is up
Feb 21 19:01:20 dogwood /kernel: vinum: mail.p1 is up
Feb 21 19:01:55 dogwood /kernel: vinum: mail.p1.s0 is up
Feb 21 19:01:55 dogwood /kernel: vinum: mail.p1.s1 is up
Feb 21 19:01:55 dogwood /kernel: vinum: mail.p1 is faulty
Feb 21 19:02:25 dogwood /kernel: vinum: removing mail.p1
Feb 21 19:02:25 dogwood /kernel: vinum: invalid plex type 0 in bre
Feb 21 19:02:55 dogwood /kernel: vinum: mail.p1.s0 is up
Feb 21 19:02:55 dogwood /kernel: vinum: mail.p1.s1 is up
Feb 21 19:02:55 dogwood /kernel: vinum: mail.p1 is up
Feb 21 19:03:20 dogwood /kernel: vinum: mail.p1.s0 is up
Feb 21 19:03:20 dogwood /kernel: vinum: mail.p1.s1 is up
Feb 21 19:03:20 dogwood /kernel: vinum: mail.p1 is faulty
[ crash ]
Feb 21 20:25:29 dogwood /kernel: Copyright (c) 1992-2001 The FreeBSD Project.
Feb 21 20:25:29 dogwood /kernel: Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
Feb 21 20:25:29 dogwood /kernel: The Regents of the University of California. All rights reserved.
Feb 21 20:25:29 dogwood /kernel: FreeBSD 4.2-STABLE #1: Thu Feb 15 11:31:58 EST 2001
Feb 21 20:25:29 dogwood /kernel: root@palm.cise.ufl.edu:/private/freebsd-src/obj/private/freebsd-src/src/sys/CISEKERN
Feb 21 20:25:29 dogwood /kernel: Timecounter "i8254" frequency 1193182 Hz
Feb 21 20:25:29 dogwood /kernel: CPU: Pentium III/Pentium III Xeon/Celeron (646.67-MHz 686-class CPU)
Feb 21 20:25:29 dogwood /kernel: Origin = "GenuineIntel" Id = 0x683 Stepping = 3
Feb 21 20:25:29 dogwood /kernel: Features=0x387fbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,PN,MMX,FXSR,SSE>
Feb 21 20:25:29 dogwood /kernel: real memory = 268369920 (262080K bytes)
[ ... ]
Feb 21 20:25:29 dogwood /kernel: da0 at ahc2 bus 0 target 0 lun 0
Feb 21 20:25:29 dogwood /kernel: da0: <QUANTUM ATLAS 10K 9WLS UCP2> Fixed Direct Access SCSI-3 device
Feb 21 20:25:29 dogwood /kernel: da0: 80.000MB/s transfers (40.000MHz, offset 31, 16bit), Tagged Queueing Enabled
Feb 21 20:25:29 dogwood /kernel: da0: 8759MB (17938986 512 byte sectors: 255H 63S/T 1116C)
Feb 21 20:25:29 dogwood /kernel: da1 at ahc1 bus 0 target 0 lun 0
Feb 21 20:25:29 dogwood /kernel: da1: <IBM DMVS36D 0250> Fixed Direct Access SCSI-3 device
Feb 21 20:25:29 dogwood /kernel: da1: 40.000MB/s transfers (20.000MHz, offset 31, 16bit), Tagged Queueing Enabled
Feb 21 20:25:29 dogwood /kernel: da1: 35003MB (71687340 512 byte sectors: 255H 63S/T 4462C)
Feb 21 20:25:29 dogwood /kernel: da4 at ahc1 bus 0 target 3 lun 0
Feb 21 20:25:29 dogwood /kernel: da4: <IBM DMVS36D 0250> Fixed Direct Access SCSI-3 device
Feb 21 20:25:29 dogwood /kernel: da4: 40.000MB/s transfers (20.000MHz, offset 31, 16bit), Tagged Queueing Enabled
Feb 21 20:25:29 dogwood /kernel: da4: 35003MB (71687340 512 byte sectors: 255H 63S/T 4462C)
Feb 21 20:25:29 dogwood /kernel: da3 at ahc1 bus 0 target 2 lun 0
Feb 21 20:25:29 dogwood /kernel: da3: <IBM DMVS36D 0250> Fixed Direct Access SCSI-3 device
Feb 21 20:25:29 dogwood /kernel: da3: 40.000MB/s transfers (20.000MHz, offset 31, 16bit), Tagged Queueing Enabled
Feb 21 20:25:29 dogwood /kernel: da3: 35003MB (71687340 512 byte sectors: 255H 63S/T 4462C)
Feb 21 20:25:29 dogwood /kernel: da2 at ahc1 bus 0 target 1 lun 0
Feb 21 20:25:29 dogwood /kernel: da2: <IBM DMVS36D 0250> Fixed Direct Access SCSI-3 device
Feb 21 20:25:29 dogwood /kernel: da2: 40.000MB/s transfers (20.000MHz, offset 31, 16bit), Tagged Queueing Enabled
Feb 21 20:25:29 dogwood /kernel: da2: 35003MB (71687340 512 byte sectors: 255H 63S/T 4462C)
Feb 21 20:25:29 dogwood /kernel: Mounting root from ufs:/dev/da0s1a
Feb 21 20:25:29 dogwood /kernel: WARNING: / was not properly dismounted
Feb 21 20:25:29 dogwood savecore: no core dump
Feb 21 20:25:33 dogwood named[266]: starting (/etc/namedb/named.conf). named 8.2.3-REL Thu Feb 15 10:16:56 EST 2001 root@palm.cise.ufl.edu:/private/freebsd-src/obj/private/freebsd-src/src/usr.sbin/named
Feb 21 20:25:33 dogwood named[266]: limit files set to fdlimit (1024)
Feb 21 20:25:33 dogwood named[266]: Zone "0.0.127.in-addr.arpa" (file 127.0.0.rev): No default TTL ($TTL <value>) set, using SOA minimum instead
Feb 21 20:25:33 dogwood named[266]: 127.0.0.rev: WARNING SOA expire value is less than 7 days (360000)
Feb 21 20:25:33 dogwood named[267]: Ready to answer queries.
Feb 21 20:25:33 dogwood rpc.lockd[286]: Couldn't find lockd in services. Assuming port 4045.
Feb 21 20:27:29 dogwood /kernel: vinum: mail.p1.s0 is down by force
Feb 21 20:27:29 dogwood /kernel: vinum: mail.p1 is faulty
Feb 21 20:27:29 dogwood /kernel: vinum: mail.p1.s1 is down by force
Feb 21 20:27:29 dogwood /kernel: vinum: mail.p1 is faulty
Feb 21 20:27:59 dogwood /kernel: vinum: removing mail.p1
Feb 21 20:30:15 dogwood ntpd[409]: time reset 0.185618 s
Feb 21 20:30:15 dogwood ntpd[409]: kernel pll status change 2041
Feb 21 20:35:44 dogwood /kernel: vinum: drive d1 is up
Feb 21 20:35:44 dogwood /kernel: vinum: drive d2 is up
Feb 21 20:35:44 dogwood /kernel: vinum: drive d3 is up
Feb 21 20:35:44 dogwood /kernel: vinum: drive d4 is up
Feb 21 20:43:08 dogwood login: ROOT LOGIN (root) ON ttyd0
Feb 21 20:45:00 dogwood /kernel: vinum: Can't open drive without drive name
Feb 21 20:45:00 dogwood last message repeated 34 times
Feb 21 20:45:00 dogwood /kernel: vinum: no drives found
Feb 21 20:45:30 dogwood /kernel: vinum: Can't open drive without drive name
Feb 21 20:45:30 dogwood last message repeated 34 times
Feb 21 20:45:30 dogwood /kernel: vinum: no drives found
Feb 21 20:45:30 dogwood /kernel: vinum: no drives found
Feb 21 20:45:30 dogwood /kernel: vinum: updating configuration from /dev/da1s1es1a
Feb 21 20:45:30 dogwood /kernel: vinum: no drives found
Feb 21 20:45:30 dogwood last message repeated 2 times
Feb 21 20:48:30 dogwood /kernel: vinum: already read config from d1
Feb 21 20:48:30 dogwood /kernel: vinum: no drives found
Feb 21 20:50:40 dogwood ntpd[409]: time reset -0.184934 s
I can try to duplicate this tomorrow, if that would be helpful.
Jim
To Unsubscribe: send mail to majordomo@FreeBSD.org
with "unsubscribe freebsd-fs" in the body of the message
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20010222053323.631B4DCD9>