Date: Thu, 20 Mar 2014 22:13:48 +0100 From: Andreas Longwitz <longwitz@incore.de> To: freebsd-fs@freebsd.org Subject: Kernel crash trying to import a ZFS pool with log device Message-ID: <532B5A0C.1010008@incore.de>
next in thread | raw e-mail | index | archive | help
On a maschine running FreeBSD 8.4-STABLE #0 r256119 I have
loader.conf: vfs.zfs.vdev.bio_delete_disable=1
-> glabel status
Name Status Components
label/C325BL31 N/A da2
label/C330CJHW N/A da3
-> gmirror status
Name Status Components
mirror/gmsv09 COMPLETE da0 (ACTIVE)
da1 (ACTIVE)
mirror/gm0 COMPLETE da4 (ACTIVE)
da5 (ACTIVE)
-> zpool status
pool: mpool
state: ONLINE
scan: scrub repaired 0 in 0h0m with 0 errors on Sat Mar 15 06:15:36 2014
config:
NAME STATE READ WRITE CKSUM
mpool ONLINE 0 0 0
mirror-0 ONLINE 0 0 0
label/C325BL31 ONLINE 0 0 0
label/C330CJHW ONLINE 0 0 0
errors: No known data errors
I can run "zpool export mpool" and "zpool import [mpool]" without any
problems.
After adding a log device from a free partition of a gmirrored disk with
-> zpool add mpool log /dev/mirror/gm0p3
the pool runs fine and I have
-> zpool status
pool: mpool
state: ONLINE
scan: scrub repaired 0 in 0h0m with 0 errors on Sat Mar 15 06:15:36 2014
config:
NAME STATE READ WRITE CKSUM
mpool ONLINE 0 0 0
mirror-0 ONLINE 0 0 0
label/C325BL31 ONLINE 0 0 0
label/C330CJHW ONLINE 0 0 0
logs
mirror/gm0p3 ONLINE 0 0 0
errors: No known data errors
But if I now run "zpool export" and "zpool import" the kernel crashes:
...
vdev_geom_open_by_path:554[1]: Found provider by name /dev/label/C325BL31.
vdev_geom_attach:102[1]: Attaching to label/C325BL31.
g_access(0xffffff0096b23a00(label/C325BL31), 1, 0, 1)
open delta:[r1w0e1] old:[r0w0e0] provider:[r0w0e0]
0xffffff0002c0d400(label/C325BL31)
g_access(0xffffff0002ba7300(da2), 1, 0, 2)
open delta:[r1w0e2] old:[r0w0e0] provider:[r0w0e0] 0xffffff0002a23800(da2)
g_disk_access(da2, 1, 0, 2)
vdev_geom_attach:123[1]: Created geom and consumer for label/C325BL31.
vdev_geom_read_config:248[1]: Reading config from label/C325BL31...
vdev_geom_open_by_path:569[1]: guid match for provider /dev/label/C325BL31.
vdev_geom_open_by_path:554[1]: Found provider by name /dev/label/C330CJHW.
vdev_geom_attach:102[1]: Attaching to label/C330CJHW.
g_access(0xffffff00969a5280(label/C330CJHW), 1, 0, 1)
open delta:[r1w0e1] old:[r0w0e0] provider:[r0w0e0]
0xffffff0002c02100(label/C330CJHW)
g_access(0xffffff0002b96280(da3), 1, 0, 2)
open delta:[r1w0e2] old:[r0w0e0] provider:[r0w0e0] 0xffffff0002a23b00(da3)
g_disk_access(da3, 1, 0, 2)
vdev_geom_attach:143[1]: Created consumer for label/C330CJHW.
vdev_geom_read_config:248[1]: Reading config from label/C330CJHW...
vdev_geom_open_by_path:569[1]: guid match for provider /dev/label/C330CJHW.
vdev_geom_open_by_path:554[1]: Found provider by name /dev/mirror/gm0p3.
vdev_geom_attach:102[1]: Attaching to mirror/gm0p3.
g_access(0xffffff0096b24180(mirror/gm0p3), 1, 0, 1)
open delta:[r1w0e1] old:[r0w0e0] provider:[r0w0e0]
0xffffff00969c7e00(mirror/gm0p3)
g_part_access(mirror/gm0p3,1,0,1)
g_access(0xffffff0096c0f800(mirror/gm0), 1, 0, 1)
open delta:[r1w0e1] old:[r8w8e16] provider:[r8w8e16]
0xffffff00969c7d00(mirror/gm0)
GEOM_MIRROR[2]: Access request for mirror/gm0: r1w0e1.
vdev_geom_attach:143[1]: Created consumer for mirror/gm0p3.
vdev_geom_read_config:248[1]: Reading config from mirror/gm0p3...
vdev_geom_open_by_path:569[1]: guid match for provider /dev/mirror/gm0p3.
g_post_event_x(0xffffffff80b16830, 0xffffff0096b24180, 2, 0)
vdev_geom_detach:163[1]: Closing access to mirror/gm0p3.
g_access(0xffffff0096b24180(mirror/gm0p3), -1, 0, -1)
open delta:[r-1w0e-1] old:[r1w0e1] provider:[r1w0e1]
0xffffff00969c7e00(mirror/gm0p3)
g_part_access(mirror/gm0p3,-1,0,-1)
g_access(0xffffff0096c0f800(mirror/gm0), -1, 0, -1)
open delta:[r-1w0e-1] old:[r9w8e17] provider:[r9w8e17]
0xffffff00969c7d00(mirror/gm0)
GEOM_MIRROR[2]: Access request for mirror/gm0: r-1w0e-1.
vdev_geom_open_by_path:554[1]: Found provider by name /dev/mirror/gm0p3.
vdev_geom_attach:102[1]: Attaching to mirror/gm0p3.
vdev_geom_attach:128[1]: Found consumer for mirror/gm0p3.
g_access(0xffffff0096b24180(mirror/gm0p3), 1, 0, 1)
open delta:[r1w0e1] old:[r1w0e1] provider:[r1w0e1]
0xffffff00969c7e00(mirror/gm0p3)
g_part_access(mirror/gm0p3,1,0,1)
g_access(0xffffff0096c0f800(mirror/gm0), 1, 0, 1)
Open delta:[r1w0e1] old:[r9w8e17] provider:[r9w8e17]
0xffffff00969c7d00(mirror/gm0)
GEOM_MIRROR[2]: Access request for mirror/gm0: r1w0e1.
vdev_geom_detach:167[1]: Destroyed consumer to mirror/gm0p3.
g_detach(0xffffff0096b24180)
g_destroy_consumer(0xffffff0096b24180)
vdev_geom_attach:147[1]: Used existing consumer for mirror/gm0p3.
vdev_geom_read_config:248[1]:
Fatal trap 12: page fault while in kernel mode
cpuid = 1; apic id = 01
fault virtual address = 0x0
fault code = supervisor read data, page not present
instruction pointer = 0x20:0xffffffff80b16f01
stack pointer = 0x28:0xffffff82452325b0
frame pointer = 0x28:0xffffff8245232650
code segment = base 0x0, limit 0xfffff, type 0x1b
= DPL 0, pres 1, long 1, def32 0, gran 1
processor eflags = interrupt enabled, resume, IOPL = 0
current process = 15494 (initial thread)
[thread pid 15494 tid 100151 ]
Stopped at vdev_geom_read_config+0x71: movq (%rdx),%rsi
(kgdb) where
...
#9 0xffffffff805dce1b in trap (frame=0xffffff8245232500) at
/usr/src/sys/amd64/amd64/trap.c:457
#10 0xffffffff805c3024 in calltrap () at
/usr/src/sys/amd64/amd64/exception.S:228
#11 0xffffffff80b16f01 in vdev_geom_read_config (cp=0xffffff0096b24180,
config=0xffffff8245232670)
at
/usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/vdev_geom.c:248
#12 0xffffffff80b17194 in vdev_geom_read_guid (cp=<value optimized out>)
at
/usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/vdev_geom.c:454
#13 0xffffffff80b172f0 in vdev_geom_open_by_path (vd=0xffffff0002b2f000,
check_guid=1)
at
/usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/vdev_geom.c:559
#14 0xffffffff80b17528 in vdev_geom_open (vd=0xffffff0002b2f000,
psize=0xffffff8245232760, max_psize=0xffffff8245232758,
ashift=0xffffff8245232750) at
/usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/vdev_geom.c:608
#15 0xffffffff80aca87a in vdev_open (vd=0xffffff0002b2f000)
at
/usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/vdev.c:1153
#16 0xffffffff80acac5e in vdev_reopen (vd=0xffffff0002b2f000)
at
/usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/vdev.c:1514
#17 0xffffffff80ab84e0 in spa_load (spa=0xffffff0002b85000,
state=SPA_LOAD_TRYIMPORT, type=SPA_IMPORT_EXISTING,
mosconfig=<value optimized out>) at
/usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/spa.c:1654
#18 0xffffffff80abaa40 in spa_tryimport (tryconfig=0xffffff00024b2260)
at
/usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/spa.c:4184
#19 0xffffffff80afb486 in zfs_ioc_pool_tryimport (zc=0xffffff8001f1d000)
at
/usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_ioctl.c:1630
#20 0xffffffff80afea7f in zfsdev_ioctl (dev=<value optimized out>,
zcmd=<value optimized out>, arg=0xffffff00966154c0 "\003",
flag=3, td=<value optimized out>) at
/usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_ioctl.c:5945
#21 0xffffffff8037729b in devfs_ioctl_f (fp=0xffffff0002c98960,
com=3222821382, data=<value optimized out>,
cred=<value optimized out>, td=0xffffff0096017000) at
/usr/src/sys/fs/devfs/devfs_vnops.c:700
#22 0xffffffff80444b22 in kern_ioctl (td=<value optimized out>,
fd=<value optimized out>, com=3222821382,
data=0xffffff00966154c0 "\003") at file.h:277
#23 0xffffffff80444d5d in ioctl (td=0xffffff0096017000,
uap=0xffffff8245232bb0) at /usr/src/sys/kern/sys_generic.c:679
#24 0xffffffff805dbca4 in amd64_syscall (td=0xffffff0096017000,
traced=0) at subr_syscall.c:114
#25 0xffffffff805c331c in Xfast_syscall () at
/usr/src/sys/amd64/amd64/exception.S:387
#26 0x0000000180fcec2c in ?? ()
(kgdb) f 11
#11 0xffffffff80b16f01 in vdev_geom_read_config (cp=0xffffff0096b24180,
config=0xffffff8245232670)
at
/usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/vdev_geom.c:248
248 ZFS_LOG(1, "Reading config from %s...", pp->name);
(kgdb) list
243 int error, l, len;
244
245 g_topology_assert_not();
246
247 pp = cp->provider;
248 ZFS_LOG(1, "Reading config from %s...", pp->name);
249
250 psize = pp->mediasize;
251 psize = P2ALIGN(psize, (uint64_t)sizeof(vdev_label_t));
252
(kgdb) p *cp
$1 = {geom = 0xffffff0002c0dd00, consumer = {le_next =
0xffffff00969a5280, le_prev = 0xffffff0002c0dd20}, provider = 0x0,
consumers = {le_next = 0xffffff009607bb00, le_prev =
0xffffff00969c7e20}, acr = 1, acw = 0, ace = 1, spoiled = 0,
stat = 0xffffff0002bed5a0, nstart = 17, nend = 17, private = 0x0,
index = 0}
(kgdb) p *cp->provider
Cannot access memory at address 0x0
(kgdb) f 12
#12 0xffffffff80b17194 in vdev_geom_read_guid (cp=<value optimized out>)
at
/usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/vdev_geom.c:454
454 if (vdev_geom_read_config(cp, &config) == 0) {
(kgdb) p *cp
$2 = {geom = 0xffffff0002c0dd00, consumer = {le_next =
0xffffff00969a5280, le_prev = 0xffffff0002c0dd20}, provider = 0x0,
consumers = {le_next = 0xffffff009607bb00, le_prev =
0xffffff00969c7e20}, acr = 1, acw = 0, ace = 1, spoiled = 0,
stat = 0xffffff0002bed5a0, nstart = 17, nend = 17, private = 0x0,
index = 0}
(kgdb) info local
config = (nvlist_t *) 0xffffff0002b85000
guid = 0
(kgdb) list
449 uint64_t guid;
450
451 g_topology_assert_not();
452
453 guid = 0;
454 if (vdev_geom_read_config(cp, &config) == 0) {
455 guid = nvlist_get_guid(config);
456 nvlist_free(config);
457 }
458 return (guid);
(kgdb) f 13
#13 0xffffffff80b172f0 in vdev_geom_open_by_path (vd=0xffffff0002b2f000,
check_guid=1)
at
/usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/vdev_geom.c:559
559 guid = vdev_geom_read_guid(cp);
(kgdb) list
554 ZFS_LOG(1, "Found provider by name %s.",
vd->vdev_path);
555 cp = vdev_geom_attach(pp);
556 if (cp != NULL && check_guid &&
ISP2(pp->sectorsize) &&
557 pp->sectorsize <= VDEV_PAD_SIZE) {
558 g_topology_unlock();
559 guid = vdev_geom_read_guid(cp);
560 g_topology_lock();
561 if (guid != vd->vdev_guid) {
562 vdev_geom_detach(cp, 0);
563 cp = NULL;
(kgdb) info local
pp = (struct g_provider *) 0xffffff00969c7e00
cp = (struct g_consumer *) 0xffffff0096b24180
guid = <value optimized out>
__func__ = "ÿÿ\000\000H\213uÀ\211Ø\211\235üþÿÿ\203À\001\205ÀH\213"
(kgdb) p *cp
$3 = {geom = 0xffffff0002c0dd00, consumer = {le_next =
0xffffff00969a5280, le_prev = 0xffffff0002c0dd20}, provider = 0x0,
consumers = {le_next = 0xffffff009607bb00, le_prev =
0xffffff00969c7e20}, acr = 1, acw = 0, ace = 1, spoiled = 0,
stat = 0xffffff0002bed5a0, nstart = 17, nend = 17, private = 0x0,
index = 0}
(kgdb) p *pp
$4 = {name = 0xffffff00969c7e88 "mirror/gm0p3", provider = {le_next =
0xffffff009698a100, le_prev = 0xffffff0002c03208},
geom = 0xffffff0002c68000, consumers = {lh_first =
0xffffff009607bb00}, acr = 1, acw = 0, ace = 1, error = 0, orphan = {
tqe_next = 0x0, tqe_prev = 0x0}, mediasize = 8589934592, sectorsize
= 512, stripesize = 0, stripeoffset = 226575360,
stat = 0xffffff0002be7120, nstart = 157, nend = 157, flags = 0,
private = 0xffffff00969c7c00, index = 2}
(kgdb) quit
The technical reason for the crash is that in "f 11" we have pp =
cp->provider = 0.
I can give more information from the kernel dump, also I can easy repeat
the crash.
--
Andreas Longwitz
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?532B5A0C.1010008>