From owner-freebsd-acpi@FreeBSD.ORG Fri Oct 29 00:34:18 2010 Return-Path: Delivered-To: freebsd-acpi@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 432D0106566B for ; Fri, 29 Oct 2010 00:34:18 +0000 (UTC) (envelope-from ming.m.lin@intel.com) Received: from mga03.intel.com (mga03.intel.com [143.182.124.21]) by mx1.freebsd.org (Postfix) with ESMTP id EBC028FC12 for ; Fri, 29 Oct 2010 00:34:17 +0000 (UTC) Received: from azsmga001.ch.intel.com ([10.2.17.19]) by azsmga101.ch.intel.com with ESMTP; 28 Oct 2010 17:34:17 -0700 X-ExtLoop1: 1 X-IronPort-AV: E=Sophos;i="4.58,255,1286175600"; d="scan'208";a="341898498" Received: from minggr.sh.intel.com (HELO [10.239.13.26]) ([10.239.13.26]) by azsmga001.ch.intel.com with ESMTP; 28 Oct 2010 17:34:15 -0700 From: Lin Ming To: Hans Petter Selasky , Andriy Gapon , Jung-uk Kim In-Reply-To: <201010281810.23668.hselasky@c2i.net> References: <201010121209.06397.hselasky@c2i.net> <1288278300.2459.19.camel@localhost> <1288279472.2459.22.camel@localhost> <201010281810.23668.hselasky@c2i.net> Content-Type: multipart/mixed; boundary="=-sZDwWjjHlziOoEmF+86n" Date: Fri, 29 Oct 2010 08:34:36 +0800 Message-ID: <1288312476.13315.15.camel@minggr.sh.intel.com> Mime-Version: 1.0 X-Mailer: Evolution 2.30.2 Cc: freebsd-acpi@freebsd.org, "Moore, Robert" Subject: Re: MacBookPro 5,1 X-BeenThere: freebsd-acpi@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: ACPI and power management development List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 29 Oct 2010 00:34:18 -0000 --=-sZDwWjjHlziOoEmF+86n Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: 7bit On Fri, 2010-10-29 at 00:10 +0800, Hans Petter Selasky wrote: > On Thursday 28 October 2010 17:24:32 Lin Ming wrote: > > On Thu, 2010-10-28 at 23:05 +0800, Lin Ming wrote: > > > On Thu, 2010-10-28 at 22:55 +0800, Hans Petter Selasky wrote: > > > > On Thursday 28 October 2010 16:44:55 Lin Ming wrote: > > > > > On Thu, 2010-10-28 at 22:40 +0800, Hans Petter Selasky wrote: > > > > > > I make two kernel builds, one with the following patch, and one > > > > > > without. > > > > > > > > > > > > > > > > > > > > > Did you get the information you needed? Or do I need to send the > > > > > > complete dmesg? > > > > > > > > > > Yes, please send both dmesgs (with and without the patch) > > > > > > > > > > Thanks. > > > > > > > > > > > --HPS > > > > > > DEBUG: Aml=0xffffff00031f9000, EndAml=0xffffff00031f900d, > > > AmlSizeNeeded=13 DEBUG: Aml=0xffffff00031f9000, MinimumLength=9, > > > AmlResourceSource=0xffffff00031f9009 DEBUG: string length=16 > > > > > > AmlSizeNeeded=13, but string length=16, there is something pretty wrong. > > > > > > Thanks for the info. > > > I'm checking... > > > > I find the evil, the resource buffer passed in by driver is wrong. > > > > Would you please try below patch? > > Just apply below patch, no kernel boot acpi options and no other > > patches. > > > > diff --git a/source/components/resources/rscalc.c > > b/source/components/resources/rscalc.c index 3215c9e..e68b5af 100644 > > --- a/source/components/resources/rscalc.c > > +++ b/source/components/resources/rscalc.c > > @@ -203,7 +203,13 @@ AcpiRsStructOptionLength ( > > */ > > if (ResourceSource->StringPtr) > > { > > - return ((ACPI_RS_LENGTH) (ResourceSource->StringLength + 1)); > > + if (ACPI_STRLEN (ResourceSource->StringPtr) + 1 != > > ResourceSource->StringLength) + { > > + AcpiOsPrintf("Bug: the passed in resource buffer is wrong, > > ResourceSource->StringLength=%d, " + "but the real string > > length is %d\n", > > + ResourceSource->StringLength, ACPI_STRLEN > > (ResourceSource->StringPtr) + 1); + } > > + return ((ACPI_RS_LENGTH) ((ACPI_STRLEN (ResourceSource->StringPtr) > > + 1) + 1)); } > > > > return (0); > > > > > Lin Ming > > That seems to have done the trick! There are some additional debug prints from > some other sub-systems which you can ignore. > > 1) copied fresh ACPICA sources from kernel tree. > 2) compiled with your patch. > 3) Resulting dmesg is attached. Hi, guys Hans and I have found the root cause of this bug. The ResourceSource->StringLength set by up layer driver is wrong, see the patch below. Below patch fixes the bug and on Hans' machine it prints, Bug: the passed in resource buffer is wrong, Resource->StringLength=1, but the real string length is 10 Bug: the passed in resource buffer is wrong, Resource->StringLength=1, but the real string length is 10 Bug: the passed in resource buffer is wrong, Resource->StringLength=1, but the real string length is 10 Bug: the passed in resource buffer is wrong, Resource->StringLength=1, but the real string length is 8 Bug: the passed in resource buffer is wrong, Resource->StringLength=1, but the real string length is 10 Bug: the passed in resource buffer is wrong, Resource->StringLength=1, but the real string length is 10 Bug: the passed in resource buffer is wrong, Resource->StringLength=1, but the real string length is 10 Bug: the passed in resource buffer is wrong, Resource->StringLength=1, but the real string length is 10 Bug: the passed in resource buffer is wrong, Resource->StringLength=1, but the real string length is 10 The full dmesg also attached. Kim, Could you write a fix in up layer code(seems in acpi_pci_link_route_irqs)? Thanks. diff --git a/source/components/resources/rscalc.c b/source/components/resources/rscalc.c index 3215c9e..e68b5af 100644 --- a/source/components/resources/rscalc.c +++ b/source/components/resources/rscalc.c @@ -203,7 +203,13 @@ AcpiRsStructOptionLength ( */ if (ResourceSource->StringPtr) { - return ((ACPI_RS_LENGTH) (ResourceSource->StringLength + 1)); + if (ACPI_STRLEN (ResourceSource->StringPtr) + 1 != ResourceSource->StringLength) + { + AcpiOsPrintf("Bug: the passed in resource buffer is wrong, ResourceSource->StringLength=%d, " + "but the real string length is %d\n", + ResourceSource->StringLength, ACPI_STRLEN (ResourceSource->StringPtr) + 1); + } + return ((ACPI_RS_LENGTH) ((ACPI_STRLEN (ResourceSource->StringPtr) + 1) + 1)); } return (0); --=-sZDwWjjHlziOoEmF+86n Content-Disposition: attachment; filename="dmesg.freebsd" Content-Type: text/plain; name="dmesg.freebsd"; charset="UTF-8" Content-Transfer-Encoding: 7bit Copyright (c) 1992-2010 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 is a registered trademark of The FreeBSD Foundation. FreeBSD 9.0-CURRENT #88: Thu Oct 28 18:05:11 CEST 2010 root@hpsbook:/usr/obj/usr/src/sys/GENERIC amd64 WARNING: WITNESS option enabled, expect reduced performance. MEMGUARD DEBUGGING ALLOCATOR INITIALIZED: MEMGUARD map base: 0xffffff8000200000 MEMGUARD map limit: 0xffffff8003a99000 MEMGUARD map size: 59346944 (Bytes) CPU: Intel(R) Core(TM)2 Duo CPU P7550 @ 2.26GHz (2255.39-MHz K8-class CPU) Origin = "GenuineIntel" Id = 0x1067a Family = 6 Model = 17 Stepping = 10 Features=0xbfebfbff Features2=0x408e3bd AMD Features=0x20100800 AMD Features2=0x1 TSC: P-state invariant real memory = 2147483648 (2048 MB) avail memory = 1768013824 (1686 MB) Event timer "LAPIC" frequency 0 Hz quality 500 ACPI APIC Table: FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs FreeBSD/SMP: 1 package(s) x 2 core(s) cpu0 (BSP): APIC ID: 0 cpu1 (AP): APIC ID: 1 ioapic0: Changing APIC ID to 1 ioapic0 irqs 0-23 on motherboard Cuse4BSD v0.1.13 @ /dev/cuse kbd0 at kbdmux0 acpi0: on motherboard acpi0: [ITHREAD] acpi_ec0: port 0x62,0x66 on acpi0 acpi0: Power Button (fixed) unknown: I/O range not supported acpi_hpet0: iomem 0xfed00000-0xfed003ff irq 0,8 on acpi0 Timecounter "HPET" frequency 25000000 Hz quality 900 Timecounter "ACPI-safe" frequency 3579545 Hz quality 850 acpi_timer0: <24-bit timer at 3.579545MHz> port 0x408-0x40b on acpi0 cpu0: on acpi0 cpu1: on acpi0 acpi_acad0: on acpi0 acpi_lid0: on acpi0 acpi_lid0: enable wake failed acpi_button0: on acpi0 acpi_button1: on acpi0 pcib0: on acpi0 pci0: on pcib0 Bug: the passed in resource buffer is wrong, Resource->StringLength=1, but the real string length is 10 Bug: the passed in resource buffer is wrong, Resource->StringLength=1, but the real string length is 10 Bug: the passed in resource buffer is wrong, Resource->StringLength=1, but the real string length is 10 Bug: the passed in resource buffer is wrong, Resource->StringLength=1, but the real string length is 8 Bug: the passed in resource buffer is wrong, Resource->StringLength=1, but the real string length is 10 Bug: the passed in resource buffer is wrong, Resource->StringLength=1, but the real string length is 10 Bug: the passed in resource buffer is wrong, Resource->StringLength=1, but the real string length is 10 Bug: the passed in resource buffer is wrong, Resource->StringLength=1, but the real string length is 10 Bug: the passed in resource buffer is wrong, Resource->StringLength=1, but the real string length is 10 (null) from acpi0(null) from acpi0(null) from acpi0(null) from acpi0(null) from acpi0(null) from acpi0(null) from acpi0(null) from acpi0(null) from acpi0(null) from acpi0(null) from acpi0(null) from acpi0(null) from acpi0(null) from acpi0(null) from acpi0(null) from acpi0(null) from acpi0(null) from acpi0pci0: at device 0.1 (no driver attached) isab0: port 0x2000-0x20ff at device 3.0 on pci0 isa0: on isab0 pci0: at device 3.1 (no driver attached) pci0: at device 3.2 (no driver attached) pci0: at device 3.3 (no driver attached) pci0: at device 3.4 (no driver attached) pci0: at device 3.5 (no driver attached) ohci0: mem 0x93488000-0x93488fff irq 18 at device 4.0 on pci0 ohci0: [ITHREAD] usbus0: on ohci0 ehci0: mem 0x93489200-0x934892ff irq 19 at device 4.1 on pci0 ehci0: [ITHREAD] usbus1: EHCI version 1.0 usbus1: on ehci0 ohci1: mem 0x93487000-0x93487fff irq 20 at device 6.0 on pci0 ohci1: [ITHREAD] usbus2: on ohci1 ehci1: mem 0x93489100-0x934891ff irq 21 at device 6.1 on pci0 ehci1: [ITHREAD] usbus3: EHCI version 1.0 usbus3: on ehci1 hdac0: mem 0x93480000-0x93483fff irq 22 at device 8.0 on pci0 hdac0: HDA Driver Revision: 20100226_0142 hdac0: [ITHREAD] pcib1: at device 9.0 on pci0 pci1: on pcib1 nfe0: port 0x21e0-0x21e7 mem 0x93486000-0x93486fff,0x93489000-0x934890ff,0x93489300-0x9348930f irq 23 at device 10.0 on pci0 miibus0: on nfe0 rgephy0: PHY 1 on miibus0 rgephy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, 1000baseT-FDX, auto nfe0: Ethernet address: 00:25:4b:cd:5a:7e nfe0: [FILTER] atapci0: port 0x21d8-0x21df,0x21ec-0x21ef,0x21d0-0x21d7,0x21e8-0x21eb,0x21c0-0x21cf mem 0x93484000-0x93485fff irq 16 at device 11.0 on pci0 atapci0: [ITHREAD] atapci0: AHCI v1.20 controller with 6 3Gbps ports, PM supported ata2: on atapci0 ata2: [ITHREAD] ata3: on atapci0 ata3: [ITHREAD] pcib2: at device 16.0 on pci0 pci2: on pcib2 Bug: the passed in resource buffer is wrong, Resource->StringLength=1, but the real string length is 8 (null) from acpi0vgapci0: port 0x1000-0x107f mem 0x92000000-0x92ffffff,0x80000000-0x8fffffff,0x90000000-0x91ffffff irq 17 at device 0.0 on pci2 pcib3: at device 21.0 on pci0 pci3: on pcib3 Bug: the passed in resource buffer is wrong, Resource->StringLength=1, but the real string length is 8 (null) from acpi0pci3: at device 0.0 (no driver attached) pcib4: at device 22.0 on pci0 pci4: on pcib4 Bug: the passed in resource buffer is wrong, Resource->StringLength=1, but the real string length is 10 (null) from acpi0fwohci0: <1394 Open Host Controller Interface> mem 0x93100000-0x93100fff irq 19 at device 0.0 on pci4 fwohci0: [ITHREAD] fwohci0: OHCI version 1.10 (ROM=0) fwohci0: No. of Isochronous channels is 8. fwohci0: EUI64 00:25:4b:ff:fe:cd:5a:7e fwohci0: invalid speed 7 (fixed to 3). fwohci0: Phy 1394a available S800, 3 ports. fwohci0: Link S800, max_rec 4096 bytes. firewire0: on fwohci0 fwe0: on firewire0 if_fwe0: Fake Ethernet address: 02:25:4b:cd:5a:7e fwe0: Ethernet address: 02:25:4b:cd:5a:7e fwip0: on firewire0 fwip0: Firewire address: 00:25:4b:ff:fe:cd:5a:7e @ 0xfffe00000000, S800, maxrec 4096 sbp0: on firewire0 dcons_crom0: on firewire0 dcons_crom0: bus_addr 0x11f4000 fwohci0: Initiate bus reset fwohci0: fwohci_intr_core: BUS reset fwohci0: fwohci_intr_core: node_id=0x00000000, SelfID Count=2, CYCLEMASTER mode battery0: on acpi0 atrtc0: port 0x70-0x77 on acpi0 RTC BIOS diagnostic error f3 atrtc0: [FILTER] Event timer "RTC" frequency 32768 Hz quality 0 attimer0: port 0x40-0x43 on acpi0 Timecounter "i8254" frequency 1193182 Hz quality 0 attimer0: [FILTER] Event timer "i8254" frequency 1193182 Hz quality 100 orm0: at iomem 0xc0000-0xce7ff on isa0 sc0: at flags 0x100 on isa0 sc0: VGA <16 virtual consoles, flags=0x300> vga0: at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0 ppc0: cannot reserve I/O port range est0: on cpu0 p4tcc0: on cpu0 est1: on cpu1 p4tcc1: on cpu1 Starting kernel event timers: LAPIC @ 1000Hz, i8254 @ 128Hz Timecounters tick every 1.000 msec firewire0: 1 nodes, maxhop <= 0 cable IRM irm(0) (me) firewire0: bus manager 0 usbus0: 12Mbps Full Speed USB v1.0 usbus1: 480Mbps High Speed USB v2.0 usbus2: 12Mbps Full Speed USB v1.0 usbus3: 480Mbps High Speed USB v2.0 ad4: 152627MB at ata2-master UDMA100 SATA 1.5Gb/s ugen0.1: at usbus0 uhub0: on usbus0 ugen1.1: at usbus1 uhub1: on usbus1 ugen2.1: at usbus2 uhub2: on usbus2 ugen3.1: at usbus3 uhub3: on usbus3 acd0: DVDR at ata3-master UDMA66 SATA 1.5Gb/s hdac0: HDA Codec #0: Cirrus Logic CS4206 pcm0: at cad 0 nid 1 on hdac0 pcm1: at cad 0 nid 1 on hdac0 pcm2: at cad 0 nid 1 on hdac0 GEOM: ad4p3: geometry does not match label (255h,63s != 16h,63s). GEOM: ad4p3: media size does not match label. GEOM: gpt/Untitled: geometry does not match label (255h,63s != 16h,63s). GEOM: gpt/Untitled: media size does not match label. GEOM: gptid/2027da8d-8557-46dc-b0b2-9481d6ca9ef4: geometry does not match label (255h,63s != 16h,63s). GEOM: gptid/2027da8d-8557-46dc-b0b2-9481d6ca9ef4: media size does not match label. uhub2: 5 ports with 5 removable, self powered uhub0: 7 ports with 7 removable, self powered uhub3: 5 ports with 5 removable, self powered uhub1: 7 ports with 7 removable, self powered ugen2.2: at usbus2 uhub4: on usbus2 ugen3.2: at usbus3 umass0: on usbus3 umass0: SCSI over Bulk-Only; quirks = 0x0000 ugen1.2: at usbus1 (null) from uhub1uhub4: 3 ports with 0 removable, self powered umass0:1:0:-1: Attached to scbus1 (probe7:umass-sim0:0:0:0): TEST UNIT READY. CDB: 0 0 0 0 0 0 (probe7:umass-sim0:0:0:0): CAM status: SCSI Status Error (probe7:umass-sim0:0:0:0): SCSI status: Check Condition (probe7:umass-sim0:0:0:0): SCSI sense: NOT READY asc:3a,0 (Medium not present) SMP: AP CPU #1 Launched! WARNING: WITNESS option enabled, expect reduced performance. da0 at umass-sim0 bus 0 scbus1 target 0 lun 0 da0: Removable Direct Access SCSI-0 device da0: 40.000MB/s transfers da0: Attempt to query device size failed: NOT READY, Medium not present Root mount waiting for: usbus1 ugen2.3: at usbus2 (null) from uhub4Trying to mount root from ufs:/dev/ufs/hpsRoot ugen0.2: at usbus0 uhid0: on usbus0 ugen2.4: at usbus2 ukbd0: on usbus2 kbd1 at ukbd0 ugen0.3: at usbus0 ukbd1: on usbus0 kbd2 at ukbd1 uhid1: on usbus0 ums0: on usbus0 ums0: 3 buttons and [XY] coordinates ID=2 ugen2.5: at usbus2 ums1: on usbus2 ums1: 3 buttons and [XY] coordinates ID=2 GEOM: gpt/Untitled: geometry does not match label (255h,63s != 16h,63s). GEOM: gpt/Untitled: media size does not match label. GEOM: gptid/2027da8d-8557-46dc-b0b2-9481d6ca9ef4: geometry does not match label (255h,63s != 16h,63s). GEOM: gptid/2027da8d-8557-46dc-b0b2-9481d6ca9ef4: media size does not match label. (null) from uhub1 lock order reversal: 1st 0xffffff0002bce278 ufs (ufs) @ /usr/src/sys/kern/vfs_subr.c:2090 2nd 0xffffff80239d9f38 bufwait (bufwait) @ /usr/src/sys/ufs/ffs/ffs_softdep.c:11357 3rd 0xffffff0002bce098 ufs (ufs) @ /usr/src/sys/kern/vfs_subr.c:2090 KDB: stack backtrace: db_trace_self_wrapper() at db_trace_self_wrapper+0x2a _witness_debugger() at _witness_debugger+0x2e witness_checkorder() at witness_checkorder+0x81e __lockmgr_args() at __lockmgr_args+0xd11 ffs_lock() at ffs_lock+0x8c VOP_LOCK1_APV() at VOP_LOCK1_APV+0x9b _vn_lock() at _vn_lock+0x47 vget() at vget+0x7b vfs_hash_get() at vfs_hash_get+0xd5 ffs_vgetf() at ffs_vgetf+0x48 softdep_sync_metadata() at softdep_sync_metadata+0x41b ffs_syncvnode() at ffs_syncvnode+0x213 ffs_truncate() at ffs_truncate+0x18c ufs_direnter() at ufs_direnter+0x6f1 ufs_mkdir() at ufs_mkdir+0x41f VOP_MKDIR_APV() at VOP_MKDIR_APV+0x93 kern_mkdirat() at kern_mkdirat+0x270 syscallenter() at syscallenter+0xf0 syscall() at syscall+0x4c Xfast_syscall() at Xfast_syscall+0xe1 --- syscall (136, FreeBSD ELF64, mkdir), rip = 0x800730aac, rsp = 0x7fffffffec38, rbp = 0x7fffffffef36 --- ugen3.3: at usbus3 umass1: on usbus3 umass1: SCSI over Bulk-Only; quirks = 0x0000 umass1:2:1:-1: Attached to scbus2 (probe0:umass-sim1:1:0:0): TEST UNIT READY. CDB: 0 0 0 0 0 0 (probe0:umass-sim1:1:0:0): CAM status: SCSI Status Error (probe0:umass-sim1:1:0:0): SCSI status: Check Condition (probe0:umass-sim1:1:0:0): SCSI sense: UNIT ATTENTION asc:28,0 (Not ready to ready change, medium may have changed) da1 at umass-sim1 bus 1 scbus2 target 0 lun 0 da1: Removable Direct Access SCSI-0 device da1: 40.000MB/s transfers da1: 3842MB (7868416 512 byte sectors: 255H 63S/T 489C) --=-sZDwWjjHlziOoEmF+86n--