From owner-freebsd-current@FreeBSD.ORG Sun Aug 31 00:08:57 2003 Return-Path: Delivered-To: freebsd-current@freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 98F5C16A4BF for ; Sun, 31 Aug 2003 00:08:57 -0700 (PDT) Received: from panzer.kdm.org (panzer.kdm.org [216.160.178.169]) by mx1.FreeBSD.org (Postfix) with ESMTP id 0EB0E43FEC for ; Sun, 31 Aug 2003 00:08:56 -0700 (PDT) (envelope-from ken@panzer.kdm.org) Received: from panzer.kdm.org (localhost [127.0.0.1]) by panzer.kdm.org (8.12.9/8.12.5) with ESMTP id h7V78tYU054793; Sun, 31 Aug 2003 01:08:55 -0600 (MDT) (envelope-from ken@panzer.kdm.org) Received: (from ken@localhost) by panzer.kdm.org (8.12.9/8.12.5/Submit) id h7V78sfB054792; Sun, 31 Aug 2003 01:08:54 -0600 (MDT) (envelope-from ken) Date: Sun, 31 Aug 2003 01:08:54 -0600 From: "Kenneth D. Merry" To: Poul-Henning Kamp Message-ID: <20030831070854.GA54748@panzer.kdm.org> References: <20030830040357.GA42770@panzer.kdm.org> <3821.1062228130@critter.freebsd.dk> Mime-Version: 1.0 Content-Type: multipart/mixed; boundary="vkogqOf2sHV7VnPd" Content-Disposition: inline In-Reply-To: <3821.1062228130@critter.freebsd.dk> User-Agent: Mutt/1.4.1i cc: current@FreeBSD.org Subject: Re: need some debugging help X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.1 Precedence: list List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 31 Aug 2003 07:08:57 -0000 --vkogqOf2sHV7VnPd Content-Type: text/plain; charset=us-ascii Content-Disposition: inline On Sat, Aug 30, 2003 at 09:22:10 +0200, Poul-Henning Kamp wrote: > In message <20030830040357.GA42770@panzer.kdm.org>, "Kenneth D. Merry" writes: > > >I think I have everything setup correctly, but I keep getting panics inside > >the GEOM code with these patches. (Memory modified after free.) I don't > >know whether I've just exposed some race condition, or whether I've done > >something wrong. > > Do you have any idea what goes on at/right before the panic ? > > Ie: has drives been created [disk_create()] or removed [disk_destroy()] > right before ? Well, the panic happens right after the probes complete for the various CAM devices in the system. I've got 4 SCSI disks in the system, so disk_create() has just been called 4 times. That's also the point where I fire off the task queue to create the sysctl variables for each device, though. (Right after the probe message is printed.) > My best shot, would be that disk_destroy() was called and something > somehow fiddled the related structures subsequently. > > You may want to set kern.geom.debugflags=N and see if that offers > any clues. > > N |= 1 topology events > N |= 2 bio processing (ie: many lines for each I/O) > N |= 4 access processing (open/close) I wouldn't expect that disk_destroy() is getting called, although I suppose that's possible. I had to make kern.geom.debugflags a tunable in order to get the debugging output. (The system panics before root gets mounted, so there's no way to set a sysctl variable.) Anyway, I got some debugging output, and I've attached dmesg output. Let me know whether anything in there looks suspicious or points to a possible problem. Thanks, Ken -- Kenneth Merry ken@kdm.org --vkogqOf2sHV7VnPd Content-Type: text/plain; charset=us-ascii Content-Disposition: attachment; filename="session.log.geom_trace.20030831" Content-Transfer-Encoding: quoted-printable Copyright (c) 1992-2003 The FreeBSD Project. Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994 The Regents of the University of California. All rights reserved. FreeBSD 5.1-CURRENT #8: Sun Aug 31 00:48:50 MDT 2003 ken@nargothrond.kdm.org:/usr/home/ken/perforce2/FreeBSD-ken/src/sys/i38= 6/compile/gondolin Preloaded elf kernel "/boot/kernel.test64/kernel" at 0xc05c8000. Preloaded elf module "/boot/kernel.test64/acpi.ko" at 0xc05c8274. Timecounter "i8254" frequency 1193182 Hz quality 0 CPU: Intel(R) Pentium(R) III CPU family 1266MHz (1266.07-MHz 686-class= CPU) Origin =3D "GenuineIntel" Id =3D 0x6b1 Stepping =3D 1 Features=3D0x383fbff real memory =3D 2684289024 (2559 MB) avail memory =3D 2607640576 (2486 MB) Programming 16 pins in IOAPIC #0 IOAPIC #0 intpin 2 -> irq 0 Programming 16 pins in IOAPIC #1 FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs cpu0 (BSP): apic id: 0, version: 0x00040011, at 0xfee00000 cpu1 (AP): apic id: 1, version: 0x00040011, at 0xfee00000 io0 (APIC): apic id: 4, version: 0x000f0011, at 0xfec00000 io1 (APIC): apic id: 5, version: 0x000f0011, at 0xfec01000 g_ignition g_modevent(MD, LOAD) g_post_event_x(0xc021e050, 0xc47896a0, 2 g_modevent(BSD, LOAD) g_post_event_x(0xc021e050, 0xc4789690, 2 g_modevent(MBR, LOAD) g_post_event_x(0xc021e050, 0xc4789680, 2 g_modevent(MBREXT, LOAD) g_post_event_x(0xc021e050, 0xc4789670, 2 g_modevent(CCD, LOAD) g_post_event_x(0xc021e050, 0xc4789660, 2 g_modevent(DEV, LOAD) g_post_event_x(0xc021e050, 0xc4789650, 2 g_modevent(DISK, LOAD) g_post_event_x(0xc021e050, 0xc4789620, 2 Pentium Pro MTRR support enabled ACPI-0660: *** Warning: Type override - [DEB_] had invalid type (Intege= r) for Scope operator, changed to (Scope) ACPI-0660: *** Warning: Type override - [MLIB] had invalid type (Intege= r) for Scope operator, changed to (Scope) ACPI-0660: *** Warning: Type override - [IO__] had invalid type (Intege= r) for Scope operator, changed to (Scope) ACPI-0660: *** Warning: Type override - [DATA] had invalid type (String= ) for Scope operator, changed to (Scope) ACPI-0660: *** Warning: Type override - [SIO_] had invalid type (String= ) for Scope operator, changed to (Scope) ACPI-0660: *** Warning: Type override - [SB__] had invalid type (String= ) for Scope operator, changed to (Scope) ACPI-0660: *** Warning: Type override - [PM__] had invalid type (String= ) for Scope operator, changed to (Scope) ACPI-0660: *** Warning: Type override - [ICNT] had invalid type (String= ) for Scope operator, changed to (Scope) ACPI-0660: *** Warning: Type override - [ACPI] had invalid type (String= ) for Scope operator, changed to (Scope) ACPI-0660: *** Warning: Type override - [OSB4] had invalid type (String= ) for Scope operator, changed to (Scope) ACPI-0660: *** Warning: Type override - [PM__] had invalid type (String= ) for Scope operator, changed to (Scope) ACPI-0660: *** Warning: Type override - [BIOS] had invalid type (Intege= r) for Scope operator, changed to (Scope) ACPI-0660: *** Warning: Type override - [CMOS] had invalid type (Intege= r) for Scope operator, changed to (Scope) npx0: on motherboard npx0: INT 16 interface acpi0: on motherboard acpi0: power button is handled as a fixed feature programming model. Timecounter "ACPI-safe" frequency 3579545 Hz quality 1000 pcibios: BIOS version 2.10 Using $PIR table, 10 entries at 0xc00f52e0 acpi_timer0: <32-bit timer at 3.579545MHz> port 0x508-0x50b on acpi0 acpi_cpu0: port 0x530-0x537 on acpi0 acpi_cpu1: port 0x530-0x537 on acpi0 acpi_cpu2: port 0x530-0x537 on acpi0 acpi_cpu3: port 0x530-0x537 on acpi0 acpi_button0: on acpi0 pcib0: port 0xcf8-0xcff on acpi0 pci0: on pcib0 IOAPIC #1 intpin 10 -> irq 2 IOAPIC #1 intpin 11 -> irq 5 IOAPIC #1 intpin 15 -> irq 9 pcib1: at device 0.1 on pci0 pci1: on pcib1 IOAPIC #1 intpin 14 -> irq 11 pci1: at device 0.0 (no driver attached) ahc0: port 0xd000-0xd0ff mem 0xfeaf= c000-0xfeafcfff irq 2 at device 5.0 on pci0 aic7899: Ultra160 Wide Channel A, SCSI Id=3D7, 32/253 SCBs ahc1: port 0xd800-0xd8ff mem 0xfeaf= f000-0xfeafffff irq 5 at device 5.1 on pci0 aic7899: Ultra160 Wide Channel B, SCSI Id=3D7, 32/253 SCBs fxp0: port 0xd400-0xd43f mem 0xfe900000-0xfe= 9fffff,0xfeafd000-0xfeafdfff irq 9 at device 6.0 on pci0 fxp0: Ethernet address 00:30:48:21:bb:74 miibus0: on fxp0 inphy0: on miibus0 inphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto isab0: port 0x580-0x58f at device 15.0 on pci0 isa0: on isab0 atapci0: port 0xffa0-0xffaf at device= 15.1 on pci0 ata0: at 0x1f0 irq 14 on atapci0 ata1: at 0x170 irq 15 on atapci0 pci0: at device 15.2 (no driver attached) pcib2: on acpi0 pci2: on pcib2 IOAPIC #1 intpin 8 -> irq 16 ti0: mem 0xfebfc000-0xfebfffff i= rq 16 at device 2.0 on pci2 ti0: Ethernet address: 00:02:e3:00:34:10 atkbdc0: port 0x64,0x60 irq 1 on acpi0 atkbd0: flags 0x1 irq 1 on atkbdc0 kbd0 at atkbd0 psm0: irq 12 on atkbdc0 psm0: model Generic PS/2 mouse, device ID 0 fdc0: cmd 3 failed at out byte 1 of 3 sio0 port 0x3f8-0x3ff irq 4 on acpi0 sio0: type 16550A, console sio1 port 0x2f8-0x2ff irq 3 on acpi0 sio1: type 16550A ppc0 port 0x778-0x77f,0x378-0x37f irq 7 drq 3 on acpi0 ppc0: Generic chipset (ECP/PS2/NIBBLE) in COMPATIBLE mode ppc0: FIFO with 16/16/8 bytes threshold ppbus0: on ppc0 plip0: on ppbus0 lpt0: on ppbus0 lpt0: Interrupt-driven port ppi0: on ppbus0 fdc0: cmd 3 failed at out byte 1 of 3 orm0:

gR_esmloivcaeb_lceo nCfDi-gR(OdMa 0S,C S0I,- 21 )dev igc_ep os tc_de0v:e n1t0_.x0(000xMcB0/2s1 etar7a0n,s f0exrcsb d(41f00.8000,0 M2Hz , orfeffs e0tx c1b5d)4f 0c8d00: gc_ds lpircees_ecnotn f[i2g7(5d6a800, x1 ,2 014)8=20 bgy_tsel irceec_ocrodnsf]ig (da0, 2, 1) g_slice_config(da0, 3, 1) g_access_rel(0xcb9a2e00(da0), -1, 0, 0) open delta:[r-1w0e0] old:[r1w0e0] provider:[r1w0e0] 0xcbd4f100(da0) g_disk_access(da0, -1, 0, 0) bsd_taste(BSD,da0) g_access_rel(0xcbda1400(da0), 1, 0, 0) open delta:[r1w0e0] old:[r0w0e0] provider:[r0w0e0] 0xcbd4f100(da0) g_disk_access(da0, 1, 0, 0) bio_getattr(MBR::type) bio_request(0xcbda6120) from 0xcbda1400(da0) to 0xcbd4f100(da0) cmd 8 g_io_deliver(0xcbda6120) from 0xcbda1400(da0) to 0xcbd4f100(da0) cmd 8 erro= r -3 off 0 len 4 bio_getattr(PC98::type) bio_request(0xcbda6090) from 0xcbda1400(da0) to 0xcbd4f100(da0) cmd 8 g_io_deliver(0xcbda6090) from 0xcbda1400(da0) to 0xcbd4f100(da0) cmd 8 erro= r -3 off 0 len 4 bio_request(0xcbda6000) from 0xcbda1400(da0) to 0xcbd4f100(da0) cmd 1 g_io_deliver(0xcbda6000) from 0xcbda1400(da0) to 0xcbd4f100(da0) cmd 1 erro= r 0 off 512 len 512 bio_request(0xcbda2e10) from 0xcbda1400(da0) to 0xcbd4f100(da0) cmd 1 g_io_deliver(0xcbda2e10) from 0xcbda1400(da0) to 0xcbd4f100(da0) cmd 1 erro= r 0 off 0 len 512 g_access_rel(0xcbda1400(da0), -1, 0, 0) open delta:[r-1w0e0] old:[r1w0e0] provider:[r1w0e0] 0xcbd4f100(da0) g_disk_access(da0, -1, 0, 0) g_slice_spoiled(0xcbda1400/da0) g_wither_geom(0xcbda1440(da0)) g_detach(0xcbda1400) g_destroy_consumer(0xcbda1400) g_destroy_geom(0xcbda1440(da0)) dev_taste(DEV,da1) g_mbrext_taste(MBREXT,da1) mbr_taste(MBR,da1) g_access_rel(0xcbd59000(da1), 1, 0, 0) open delta:[r1w0e0] old:[r0w0e0] provider:[r0w0e0] 0xcbd4f700(da1) g_disk_access(da1, 1, 0, 0) bio_getattr(GEOM::fwsectors) bio_request(0xcbda3ea0) from 0xcbd59000(da1) to 0xcbd4f700(da1) cmd 8 g_io_deliver(0xcbda3ea0) from 0xcbd59000(da1) to 0xcbd4f700(da1) cmd 8 erro= r 0 off 0 len 4 bio_request(0xcbda2cf0) from 0xcbd59000(da1) to 0xcbd4f700(da1) cmd 1 g_io_deliver(0xcbda2cf0) from 0xcbd59000(da1) to 0xcbd4f700(da1) cmd 1 erro= r 0 off 0 len 512 g_slice_config(da1, 0, 0) g_slice_config(da1, 1, 0) g_slice_config(da1, 2, 0) g_slice_config(da1, 3, 0) g_slice_config(da1, 0, 1) Memory modified after free 0xcbd4f600(124) panic: Most recently used by devbuf cpuid =3D 0; lapic.id =3D 00000000 Debugger("panic") Stopped at Debugger+0x55: xchgl %ebx,in_Debugger.0 db> `=08 =08trace Debugger(c03e9757,0,c03fb4e2,e5e45af0,100) at Debugger+0x55 panic(c03fb4e2,c03e7f5a,7c,c083ac14,c083ac00) at panic+0x15f mtrash_ctor(cbd4f600,80,0,57a,cbd4f600) at mtrash_ctor+0x5d uma_zalloc_arg(c083ac00,0,102,e5e45b58,e5e45b58) at uma_zalloc_arg+0x1e4 malloc(5a,c042fae0,102,1,c02756e4) at malloc+0xd3 g_new_providerf(cb9a2f00,cb9b0b90,e5e45bf8,1,1) at g_new_providerf+0xa3 g_slice_config(cb9a2f00,0,1,7e00,0) at g_slice_config+0x259 g_mbr_modify(cb9a2f00,cbd58000,cbd73000,123,0) at g_mbr_modify+0x247 g_mbr_taste(c0470580,cbd4f700,0,159,cbd4f780) at g_mbr_taste+0x1be g_new_provider_event(cbd4f700,0,c03e52b7,b3,66666667) at g_new_provider_eve= nt+0xad one_event(e5e45d0c,c021cd85,c0485fd4,0,4c) at one_event+0x218 g_run_events(c0485fd4,0,4c,c03d7a28,a) at g_run_events+0x15 g_event_procbody(0,e5e45d48,c03e7395,314,345f184d) at g_event_procbody+0x45 fork_exit(c021cd40,0,e5e45d48) at fork_exit+0xcf fork_trampoline() at fork_trampoline+0x8 --- trap 0x1, eip =3D 0, esp =3D 0xe5e45d7c, ebp =3D 0 --- db>=20 --vkogqOf2sHV7VnPd--