* 2.6.18 - AHCI detection pauses excessively
@ 2006-11-13 0:09 Berck E. Nash
2006-11-15 12:45 ` Tejun Heo
0 siblings, 1 reply; 12+ messages in thread
From: Berck E. Nash @ 2006-11-13 0:09 UTC (permalink / raw)
To: linux-kernel@vger.kernel.org
AHCI pauses heartily on during detection boot, but eventually proceeds.
I've mentioned the problem before, but have since narrowed it down a
bit. The problem does not occur in 2.6.17.3, but does occur in 2.6.18.
The problem is still occurring both in 2.6.19-rc5 as well as
2.6.19-rc5-mm1.
Please cc me on replies since I am not subscribed to LKML.
Messages surrounding the hang:
scsi2 : ahci
ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
ata2.00: qc timeout (cmd 0xec)
ata2.00: failed to IDENTIFY (I/O error, err_mask=0x104)
ata2: port is slow to respond, please be patient (Status 0x80)
ata2: port failed to respond (30 secs, Status 0x80)
ata2: COMRESET failed (device not ready)
ata2: hardreset failed, retrying in 5 secs
ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
ata2.00: ATA-6, max UDMA/133, 640 sectors: LBA
ata2.00: ata2: dev 0 multi count 1
ata2.00: configured for UDMA/133
I should note that on this system ata1 and ata3 both detect quickly, but
they have 1.5 Gbps devices whereas ata2 has a 3.0Gbps device.
The device:
00:1f.2 SATA controller: Intel Corporation 82801GR/GH (ICH7 Family)
Serial ATA Storage Controller AHCI (rev 01) (prog-if 01 [AHCI 1.0])
Subsystem: ASUSTeK Computer Inc. Unknown device 2606
Flags: bus master, 66MHz, medium devsel, latency 0, IRQ 50
I/O ports at e400 [size=8]
I/O ports at e080 [size=4]
I/O ports at e000 [size=8]
I/O ports at dc00 [size=4]
I/O ports at d880 [size=16]
Memory at febfb800 (32-bit, non-prefetchable) [size=1K]
Capabilities: <access denied>
dmesg snip from 2.6.17.3, without the hangup:
scsi1 : ahci
ata2: port reset, p_is 40000001 is 2 pis 0 cmd 4017 tf 451 ss 123 se 0
ata2: SATA link up 3.0 Gbps (SStatus 123)
ata2: dev 0 cfg 49:2f00 82:0068 83:5060 84:4000 85:0000 86:1000 87:4000
88:407f
ata2: dev 0 ATA-6, max UDMA/133, 640 sectors: LBA
ata2: dev 0 configured for UDMA/133
Thanks,
Berck
^ permalink raw reply [flat|nested] 12+ messages in thread* Re: 2.6.18 - AHCI detection pauses excessively 2006-11-13 0:09 2.6.18 - AHCI detection pauses excessively Berck E. Nash @ 2006-11-15 12:45 ` Tejun Heo 2006-11-15 18:22 ` Berck E. Nash 0 siblings, 1 reply; 12+ messages in thread From: Tejun Heo @ 2006-11-15 12:45 UTC (permalink / raw) To: Berck E. Nash; +Cc: linux-kernel@vger.kernel.org Berck E. Nash wrote: > AHCI pauses heartily on during detection boot, but eventually proceeds. > I've mentioned the problem before, but have since narrowed it down a > bit. The problem does not occur in 2.6.17.3, but does occur in 2.6.18. > The problem is still occurring both in 2.6.19-rc5 as well as > 2.6.19-rc5-mm1. > > Please cc me on replies since I am not subscribed to LKML. > > Messages surrounding the hang: > > scsi2 : ahci > ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300) > ata2.00: qc timeout (cmd 0xec) > ata2.00: failed to IDENTIFY (I/O error, err_mask=0x104) > ata2: port is slow to respond, please be patient (Status 0x80) > ata2: port failed to respond (30 secs, Status 0x80) > ata2: COMRESET failed (device not ready) > ata2: hardreset failed, retrying in 5 secs > ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300) > ata2.00: ATA-6, max UDMA/133, 640 sectors: LBA > ata2.00: ata2: dev 0 multi count 1 > ata2.00: configured for UDMA/133 > > I should note that on this system ata1 and ata3 both detect quickly, but > they have 1.5 Gbps devices whereas ata2 has a 3.0Gbps device. Hmmm.. Can you try with the attached patch applied? Also, please turn on kernel config 'Kernel Hacking -> Show timing info on printks' and report boot dmesg. Thanks. -- tejun ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: 2.6.18 - AHCI detection pauses excessively 2006-11-15 12:45 ` Tejun Heo @ 2006-11-15 18:22 ` Berck E. Nash 2006-11-23 11:20 ` JG 2006-11-27 3:35 ` Tejun Heo 0 siblings, 2 replies; 12+ messages in thread From: Berck E. Nash @ 2006-11-15 18:22 UTC (permalink / raw) To: Tejun Heo; +Cc: linux-kernel@vger.kernel.org [-- Attachment #1: Type: text/plain, Size: 1154 bytes --] Tejun Heo wrote: > Hmmm.. Can you try with the attached patch applied? Also, please turn > on kernel config 'Kernel Hacking -> Show timing info on printks' and > report boot dmesg. Looks like you forgot to attach the patch, so I couldn't test it:) Here's the section with the annoying hang with timing info. I noticed that there are similar messages repeated later, but without as much hang, so I've attached the entire dmesg as well, in case it's of any help. [ 74.774249] scsi2 : ahci [ 75.232531] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300) [ 105.197121] ata2.00: qc timeout (cmd 0xec) [ 105.197168] ata2.00: failed to IDENTIFY (I/O error, err_mask=0x104) [ 113.040691] ata2: port is slow to respond, please be patient (Status 0x80) [ 135.973052] ata2: port failed to respond (30 secs, Status 0x80) [ 135.973098] ata2: COMRESET failed (device not ready) [ 135.973145] ata2: hardreset failed, retrying in 5 secs [ 141.836829] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300) [ 142.366267] ata2.00: failed to IDENTIFY (I/O error, err_mask=0x100) [ 143.171270] ata2: SATA link down (SStatus 0 SControl 300) Berck [-- Attachment #2: dmesg --] [-- Type: text/plain, Size: 31325 bytes --] 0000, IRQs 2, 8, 0 [ 69.455284] hpet0: 3 64-bit timers, 14318180 Hz [ 69.456340] PCI-GART: No AMD northbridge found. [ 69.457171] pnp: the driver 'system' has been registered [ 69.457204] pnp: match found with the PnP device '00:01' and the driver 'system' [ 69.457211] pnp: match found with the PnP device '00:07' and the driver 'system' [ 69.457214] pnp: 00:07: ioport range 0x290-0x297 has been reserved [ 69.457263] pnp: match found with the PnP device '00:08' and the driver 'system' [ 69.457268] pnp: match found with the PnP device '00:0b' and the driver 'system' [ 69.457273] pnp: match found with the PnP device '00:0c' and the driver 'system' [ 69.457277] pnp: match found with the PnP device '00:0d' and the driver 'system' [ 69.457529] PCI: Bridge: 0000:00:01.0 [ 69.457572] IO window: disabled. [ 69.457616] MEM window: faa00000-feafffff [ 69.457660] PREFETCH window: cff00000-efefffff [ 69.457705] PCI: Bridge: 0000:00:1c.0 [ 69.457747] IO window: disabled. [ 69.457792] MEM window: disabled. [ 69.457836] PREFETCH window: cfe00000-cfefffff [ 69.457882] PCI: Bridge: 0000:00:1c.3 [ 69.457925] IO window: c000-cfff [ 69.457970] MEM window: fa900000-fa9fffff [ 69.458016] PREFETCH window: disabled. [ 69.458062] PCI: Bridge: 0000:00:1e.0 [ 69.458105] IO window: b000-bfff [ 69.458150] MEM window: fa700000-fa8fffff [ 69.458195] PREFETCH window: 50000000-500fffff [ 69.458250] ACPI: PCI Interrupt 0000:00:01.0[A] -> GSI 16 (level, low) -> IRQ 16 [ 69.458336] PCI: Setting latency timer of device 0000:00:01.0 to 64 [ 69.458350] ACPI: PCI Interrupt 0000:00:1c.0[A] -> GSI 16 (level, low) -> IRQ 16 [ 69.458437] PCI: Setting latency timer of device 0000:00:1c.0 to 64 [ 69.458452] ACPI: PCI Interrupt 0000:00:1c.3[D] -> GSI 19 (level, low) -> IRQ 19 [ 69.458542] PCI: Setting latency timer of device 0000:00:1c.3 to 64 [ 69.458551] PCI: Setting latency timer of device 0000:00:1e.0 to 64 [ 69.458574] NET: Registered protocol family 2 [ 69.470778] IP route cache hash table entries: 32768 (order: 6, 262144 bytes) [ 69.470955] TCP established hash table entries: 131072 (order: 9, 2097152 bytes) [ 69.471933] TCP bind hash table entries: 65536 (order: 8, 1048576 bytes) [ 69.472651] TCP: Hash tables configured (established 131072 bind 65536) [ 69.472698] TCP reno registered [ 69.472779] wait_for_probes: waiting for 0 threads [ 69.473533] audit: initializing netlink socket (disabled) [ 69.473588] audit(1163589194.294:1): initialized [ 69.473824] Loading Reiser4. See www.namesys.com for a description of Reiser4. [ 69.473961] io scheduler noop registered [ 69.474033] io scheduler anticipatory registered (default) [ 69.485926] PCI: Setting latency timer of device 0000:00:01.0 to 64 [ 69.485959] assign_interrupt_mode Found MSI capability [ 69.486043] Allocate Port Service[0000:00:01.0:pcie00] [ 69.486140] PCI: Setting latency timer of device 0000:00:1c.0 to 64 [ 69.486188] assign_interrupt_mode Found MSI capability [ 69.486262] Allocate Port Service[0000:00:1c.0:pcie00] [ 69.486304] Allocate Port Service[0000:00:1c.0:pcie02] [ 69.486327] PCI: Setting latency timer of device 0000:00:1c.3 to 64 [ 69.486361] assign_interrupt_mode Found MSI capability [ 69.486434] Allocate Port Service[0000:00:1c.3:pcie00] [ 69.486545] ACPI: Power Button (FF) [PWRF] [ 69.486621] ACPI: Power Button (CM) [PWRB] [ 69.486989] ACPI (exconfig-0455): Dynamic SSDT Load - OemId [ AMI] OemTableId [ CPU1PM] [20060707] [ 69.487395] ACPI: Processor [CPU1] (supports 8 throttling states) [ 69.487703] ACPI (exconfig-0455): Dynamic SSDT Load - OemId [ AMI] OemTableId [ CPU2PM] [20060707] [ 69.488101] ACPI: Processor [CPU2] (supports 8 throttling states) [ 69.488204] ACPI: Getting cpuindex for acpiid 0x3 [ 69.488251] ACPI: Getting cpuindex for acpiid 0x4 [ 69.490315] Real Time Clock Driver v1.12ac [ 69.490469] hpet_resources: 0xfed00000 is busy [ 69.490478] Linux agpgart interface v0.101 (c) Dave Jones [ 69.490524] Serial: 8250/16550 driver $Revision: 1.90 $ 4 ports, IRQ sharing disabled [ 69.490800] pnp: the driver 'serial' has been registered [ 69.491058] Uniform Multi-Platform E-IDE driver Revision: 7.00alpha2 [ 69.491105] ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx [ 69.491193] ICH7: IDE controller at PCI slot 0000:00:1f.1 [ 69.491245] ACPI: PCI Interrupt 0000:00:1f.1[A] -> GSI 22 (level, low) -> IRQ 22 [ 69.491335] ICH7: chipset revision 1 [ 69.491377] ICH7: not 100% native mode: will probe irqs later [ 69.491428] ide0: BM-DMA at 0xffa0-0xffa7, BIOS settings: hda:DMA, hdb:DMA [ 69.491549] ide1: BM-DMA at 0xffa8-0xffaf, BIOS settings: hdc:pio, hdd:pio [ 69.491667] Probing IDE interface ide0... [ 70.163549] hda: LITE-ON LTR-48246S, ATAPI CD/DVD-ROM drive [ 70.878178] hdb: _NEC DVD_RW ND-3520AW, ATAPI CD/DVD-ROM drive [ 70.931385] ide0 at 0x1f0-0x1f7,0x3f6 on irq 14 [ 70.931525] Probing IDE interface ide1... [ 71.449695] SiI680: IDE controller at PCI slot 0000:01:00.0 [ 71.449752] ACPI: PCI Interrupt 0000:01:00.0[A] -> GSI 21 (level, low) -> IRQ 21 [ 71.449842] SiI680: chipset revision 2 [ 71.449900] SiI680: BASE CLOCK == 133 [ 71.449982] SiI680: 100% native mode on irq 21 [ 71.450029] ide2: MMIO-DMA , BIOS settings: hde:pio, hdf:pio [ 71.450135] ide3: MMIO-DMA , BIOS settings: hdg:pio, hdh:pio [ 71.450240] Probing IDE interface ide2... [ 71.714929] hde: SAMSUNG WN316025A (1.6 GB), ATA DISK drive [ 72.327426] ide2 at 0xffffc2000000ec80-0xffffc2000000ec87,0xffffc2000000ec8a on irq 21 [ 72.327552] Probing IDE interface ide3... [ 72.591453] hdg: MAXTOR 6L040J2, ATA DISK drive [ 73.202922] ide3 at 0xffffc2000000ecc0-0xffffc2000000ecc7,0xffffc2000000ecca on irq 21 [ 73.203182] hde: max request size: 64KiB [ 73.203226] hde: 3145968 sectors (1610 MB) w/109KiB Cache, CHS=3121/16/63, DMA [ 73.208831] hde: hde1 [ 73.219935] hdg: max request size: 64KiB [ 73.221077] hdg: 78198750 sectors (40037 MB) w/1819KiB Cache, CHS=65535/16/63, UDMA(133) [ 73.221390] hdg: cache flushes supported [ 73.221449] hdg: hdg1 [ 73.239729] hda: ATAPI 48X CD-ROM CD-R/RW drive, 2048kB Cache, UDMA(33) [ 73.239989] Uniform CD-ROM driver Revision: 3.20 [ 73.280394] hdb: ATAPI 48X DVD-ROM DVD-R CD-R/RW drive, 2048kB Cache, UDMA(33) [ 73.294784] ACPI: PCI Interrupt 0000:01:01.0[A] -> GSI 22 (level, low) -> IRQ 22 [ 73.299579] libata version 2.00 loaded. [ 73.299620] ahci 0000:00:1f.2: version 2.0 [ 73.299647] ACPI: PCI Interrupt 0000:00:1f.2[B] -> GSI 23 (level, low) -> IRQ 23 [ 73.299940] pnp: the driver 'i8042 kbd' has been registered [ 73.299973] pnp: match found with the PnP device '00:0a' and the driver 'i8042 kbd' [ 73.299979] pnp: the driver 'i8042 aux' has been registered [ 73.300010] PNP: PS/2 Controller [PNP0303:PS2K] at 0x60,0x64 irq 1 [ 73.300133] PNP: PS/2 controller doesn't have AUX irq; using default 12 [ 73.302838] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 73.302905] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 73.303054] mice: PS/2 mouse device common for all mice [ 73.303115] EDAC MC: Ver: 2.0.1 Nov 12 2006 [ 73.303311] TCP cubic registered [ 73.303357] Initializing XFRM netlink socket [ 73.303410] NET: Registered protocol family 1 [ 73.303461] NET: Registered protocol family 17 [ 73.303511] NET: Registered protocol family 15 [ 73.303562] wait_for_probes: waiting for 3 threads [ 73.326541] input: AT Translated Set 2 keyboard as /class/input/input0 [ 73.504483] scsi0 : Adaptec AIC7XXX EISA/VLB/PCI SCSI HBA DRIVER, Rev 7.0 [ 73.504485] <Adaptec 2940 Ultra2 SCSI adapter> [ 73.504486] aic7890/91: Ultra2 Wide Channel A, SCSI Id=7, 32/253 SCBs [ 73.504487] [ 73.764444] scsi 0:0:1:0: Direct-Access IBM-PCCO ST39102LC !# B219 PQ: 0 ANSI: 2 [ 73.764508] scsi0:A:1:0: Tagged Queuing enabled. Depth 8 [ 73.764595] target0:0:1: Beginning Domain Validation [ 73.771070] target0:0:1: wide asynchronous [ 73.775828] target0:0:1: FAST-40 WIDE SCSI 80.0 MB/s ST (25 ns, offset 15) [ 73.780114] target0:0:1: Domain Validation skipping write tests [ 73.780161] target0:0:1: Ending Domain Validation [ 73.781059] SCSI device sda: 17774160 512-byte hdwr sectors (9100 MB) [ 73.783078] sda: Write Protect is off [ 73.783122] sda: Mode Sense: ab 00 10 08 [ 73.784693] SCSI device sda: drive cache: write back w/ FUA [ 73.785517] SCSI device sda: 17774160 512-byte hdwr sectors (9100 MB) [ 73.787530] sda: Write Protect is off [ 73.787574] sda: Mode Sense: ab 00 10 08 [ 73.789147] SCSI device sda: drive cache: write back w/ FUA [ 73.789194] sda: sda1 sda2 [ 73.795382] sd 0:0:1:0: Attached scsi disk sda [ 73.795475] sd 0:0:1:0: Attached scsi generic sg0 type 0 [ 73.798550] scsi 0:0:2:0: Direct-Access SGI SEAGATE ST39102L 2702 PQ: 0 ANSI: 2 [ 73.798610] scsi0:A:2:0: Tagged Queuing enabled. Depth 8 [ 73.798688] target0:0:2: Beginning Domain Validation [ 73.804025] target0:0:2: wide asynchronous [ 73.807961] target0:0:2: FAST-40 WIDE SCSI 80.0 MB/s ST (25 ns, offset 15) [ 73.811434] target0:0:2: Domain Validation skipping write tests [ 73.811481] target0:0:2: Ending Domain Validation [ 73.812364] SCSI device sdb: 17781520 512-byte hdwr sectors (9104 MB) [ 73.815781] sdb: Write Protect is off [ 73.815826] sdb: Mode Sense: cf 00 10 08 [ 73.819585] SCSI device sdb: drive cache: write back w/ FUA [ 73.820462] SCSI device sdb: 17781520 512-byte hdwr sectors (9104 MB) [ 73.823873] sdb: Write Protect is off [ 73.823917] sdb: Mode Sense: cf 00 10 08 [ 73.827680] SCSI device sdb: drive cache: write back w/ FUA [ 73.827726] sdb: sdb1 [ 73.833982] sd 0:0:2:0: Attached scsi disk sdb [ 73.834081] sd 0:0:2:0: Attached scsi generic sg1 type 0 [ 74.303870] PCI: Setting latency timer of device 0000:00:1f.2 to 64 [ 74.303877] ahci 0000:00:1f.2: AHCI 0001.0100 32 slots 4 ports 3 Gbps 0xf impl SATA mode [ 74.303937] ahci 0000:00:1f.2: flags: 64bit ncq pm led clo pio slum part [ 74.304043] ata1: SATA max UDMA/133 cmd 0xFFFFC2000001E900 ctl 0x0 bmdma 0x0 irq 316 [ 74.304170] ata2: SATA max UDMA/133 cmd 0xFFFFC2000001E980 ctl 0x0 bmdma 0x0 irq 316 [ 74.304278] ata3: SATA max UDMA/133 cmd 0xFFFFC2000001EA00 ctl 0x0 bmdma 0x0 irq 316 [ 74.304389] ata4: SATA max UDMA/133 cmd 0xFFFFC2000001EA80 ctl 0x0 bmdma 0x0 irq 316 [ 74.304450] scsi1 : ahci [ 74.761641] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300) [ 74.764015] ata1.00: ATA-6, max UDMA/133, 72303840 sectors: LBA48 [ 74.764063] ata1.00: ata1: dev 0 multi count 16 [ 74.774201] ata1.00: configured for UDMA/133 [ 74.774249] scsi2 : ahci [ 75.232531] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300) [ 105.197121] ata2.00: qc timeout (cmd 0xec) [ 105.197168] ata2.00: failed to IDENTIFY (I/O error, err_mask=0x104) [ 113.040691] ata2: port is slow to respond, please be patient (Status 0x80) [ 135.973052] ata2: port failed to respond (30 secs, Status 0x80) [ 135.973098] ata2: COMRESET failed (device not ready) [ 135.973145] ata2: hardreset failed, retrying in 5 secs [ 141.836829] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300) [ 142.366267] ata2.00: failed to IDENTIFY (I/O error, err_mask=0x100) [ 143.171270] ata2: SATA link down (SStatus 0 SControl 300) [ 143.171322] scsi3 : ahci [ 143.629025] ata3: SATA link up 1.5 Gbps (SStatus 113 SControl 300) [ 143.629851] ata3.00: ATA-7, max UDMA/133, 488397168 sectors: LBA48 NCQ (depth 31/32) [ 143.629910] ata3.00: ata3: dev 0 multi count 16 [ 143.637526] ata3.00: configured for UDMA/133 [ 143.637574] scsi4 : ahci [ 143.941875] ata4: SATA link down (SStatus 0 SControl 300) [ 143.941989] scsi 1:0:0:0: Direct-Access ATA WDC WD360GD-00FL 31.0 PQ: 0 ANSI: 5 [ 143.942136] SCSI device sdc: 72303840 512-byte hdwr sectors (37020 MB) [ 143.942189] sdc: Write Protect is off [ 143.942232] sdc: Mode Sense: 00 3a 00 00 [ 143.942245] SCSI device sdc: drive cache: write back [ 143.942319] SCSI device sdc: 72303840 512-byte hdwr sectors (37020 MB) [ 143.942373] sdc: Write Protect is off [ 143.942415] sdc: Mode Sense: 00 3a 00 00 [ 143.942428] SCSI device sdc: drive cache: write back [ 143.942473] sdc: sdc1 sdc2 [ 143.952358] sd 1:0:0:0: Attached scsi disk sdc [ 143.952454] sd 1:0:0:0: Attached scsi generic sg2 type 0 [ 143.952565] scsi 3:0:0:0: Direct-Access ATA ST3250823AS 3.03 PQ: 0 ANSI: 5 [ 143.952691] SCSI device sdd: 488397168 512-byte hdwr sectors (250059 MB) [ 143.952744] sdd: Write Protect is off [ 143.952786] sdd: Mode Sense: 00 3a 00 00 [ 143.952799] SCSI device sdd: drive cache: write back [ 143.952872] SCSI device sdd: 488397168 512-byte hdwr sectors (250059 MB) [ 143.952924] sdd: Write Protect is off [ 143.952967] sdd: Mode Sense: 00 3a 00 00 [ 143.952979] SCSI device sdd: drive cache: write back [ 143.953024] sdd: sdd1 sdd2 [ 143.973954] sd 3:0:0:0: Attached scsi disk sdd [ 143.974052] sd 3:0:0:0: Attached scsi generic sg3 type 0 [ 143.974196] wait_for_probes: waiting for 0 threads [ 143.974953] reiser4: sdc1: found disk format 4.0.0. [ 145.196509] VFS: Mounted root (reiser4 filesystem) readonly. [ 145.196604] Freeing unused kernel memory: 200k freed [ 147.360573] Floppy drive(s): fd0 is 1.44M [ 147.376273] FDC 0 is a post-1991 82077 [ 147.405642] usbcore: registered new interface driver usbfs [ 147.405709] usbcore: registered new interface driver hub [ 147.405779] usbcore: registered new device driver usb [ 147.422003] ACPI: PCI Interrupt 0000:02:00.0[A] -> GSI 19 (level, low) -> IRQ 19 [ 147.422107] PCI: Setting latency timer of device 0000:02:00.0 to 64 [ 147.422165] sky2 v1.10 addr 0xfa9fc000 irq 19 Yukon-EC (0xb6) rev 2 [ 147.422403] sky2 eth0: addr 00:18:f3:3d:1b:06 [ 147.496925] uhci_hcd: Unknown symbol usb_hcd_pci_suspend [ 147.496999] uhci_hcd: Unknown symbol usb_hcd_resume_root_hub [ 147.497061] uhci_hcd: Unknown symbol usb_hcd_pci_probe [ 147.497137] uhci_hcd: Unknown symbol usb_check_bandwidth [ 147.497226] uhci_hcd: Unknown symbol usb_disabled [ 147.497290] uhci_hcd: Unknown symbol usb_release_bandwidth [ 147.497406] uhci_hcd: Unknown symbol usb_claim_bandwidth [ 147.497487] uhci_hcd: Unknown symbol usb_hcd_pci_resume [ 147.497568] uhci_hcd: Unknown symbol usb_hcd_giveback_urb [ 147.497641] uhci_hcd: Unknown symbol usb_hcd_poll_rh_status [ 147.497723] uhci_hcd: Unknown symbol usb_hcd_pci_remove [ 147.497788] uhci_hcd: Unknown symbol usb_root_hub_lost_power [ 147.505461] ACPI: PCI Interrupt 0000:00:1d.7[A] -> GSI 20 (level, low) -> IRQ 20 [ 147.505565] PCI: Setting latency timer of device 0000:00:1d.7 to 64 [ 147.505569] ehci_hcd 0000:00:1d.7: EHCI Host Controller [ 147.505724] ehci_hcd 0000:00:1d.7: new USB bus registered, assigned bus number 1 [ 147.505834] ehci_hcd 0000:00:1d.7: debug port 1 [ 147.505884] PCI: cache line size of 32 is not supported by device 0000:00:1d.7 [ 147.505893] ehci_hcd 0000:00:1d.7: irq 20, io mem 0xfebfbc00 [ 147.509807] ehci_hcd 0000:00:1d.7: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004 [ 147.509909] usb usb1: new device found, idVendor=0000, idProduct=0000 [ 147.509958] usb usb1: new device strings: Mfr=3, Product=2, SerialNumber=1 [ 147.510008] usb usb1: Product: EHCI Host Controller [ 147.510053] usb usb1: Manufacturer: Linux 2.6.19-rc5-mm1 ehci_hcd [ 147.510101] usb usb1: SerialNumber: 0000:00:1d.7 [ 147.510225] usb usb1: configuration #1 chosen from 1 choice [ 147.510291] hub 1-0:1.0: USB hub found [ 147.510342] hub 1-0:1.0: 8 ports detected [ 147.513491] USB Universal Host Controller Interface driver v3.0 [ 147.514126] ACPI: PCI Interrupt 0000:00:1f.3[B] -> GSI 23 (level, low) -> IRQ 23 [ 147.514225] i801_smbus 0000:00:1f.3: SMBus using PCI Interrupt [ 147.514262] i2c_adapter i2c-0: adapter [SMBus I801 adapter at 0400] registered [ 147.514288] ACPI: PCI Interrupt 0000:00:1d.0[A] -> GSI 20 (level, low) -> IRQ 20 [ 147.514387] PCI: Setting latency timer of device 0000:00:1d.0 to 64 [ 147.514391] uhci_hcd 0000:00:1d.0: UHCI Host Controller [ 147.514459] uhci_hcd 0000:00:1d.0: new USB bus registered, assigned bus number 2 [ 147.514539] uhci_hcd 0000:00:1d.0: irq 20, io base 0x0000e480 [ 147.514634] ACPI: PCI Interrupt 0000:00:1d.1[B] -> GSI 17 (level, low) -> IRQ 17 [ 147.520329] PCI: Setting latency timer of device 0000:00:1d.1 to 64 [ 147.520333] uhci_hcd 0000:00:1d.1: UHCI Host Controller [ 147.520433] usb usb2: new device found, idVendor=0000, idProduct=0000 [ 147.520483] usb usb2: new device strings: Mfr=3, Product=2, SerialNumber=1 [ 147.520531] usb usb2: Product: UHCI Host Controller [ 147.520577] usb usb2: Manufacturer: Linux 2.6.19-rc5-mm1 uhci_hcd [ 147.520624] usb usb2: SerialNumber: 0000:00:1d.0 [ 147.520733] usb usb2: configuration #1 chosen from 1 choice [ 147.520802] hub 2-0:1.0: USB hub found [ 147.520851] hub 2-0:1.0: 2 ports detected [ 147.520919] uhci_hcd 0000:00:1d.1: new USB bus registered, assigned bus number 3 [ 147.521005] uhci_hcd 0000:00:1d.1: irq 17, io base 0x0000e800 [ 147.523530] ACPI: PCI Interrupt 0000:00:1d.2[C] -> <6>usb usb3: new device found, idVendor=0000, idProduct=0000 [ 147.523573] usb usb3: new device strings: Mfr=3, Product=2, SerialNumber=1 [ 147.523577] usb usb3: Product: UHCI Host Controller [ 147.523579] usb usb3: Manufacturer: Linux 2.6.19-rc5-mm1 uhci_hcd [ 147.523581] usb usb3: SerialNumber: 0000:00:1d.1 [ 147.523646] usb usb3: configuration #1 chosen from 1 choice [ 147.523669] hub 3-0:1.0: USB hub found [ 147.523675] hub 3-0:1.0: 2 ports detected [ 147.523704] ACPI: PCI Interrupt 0000:00:1d.3[D] -> GSI 19 (level, low) -> IRQ 19 [ 147.523716] PCI: Setting latency timer of device 0000:00:1d.3 to 64 [ 147.523719] uhci_hcd 0000:00:1d.3: UHCI Host Controller [ 147.523741] uhci_hcd 0000:00:1d.3: new USB bus registered, assigned bus number 4 [ 147.523777] uhci_hcd 0000:00:1d.3: irq 19, io base 0x0000ec00 [ 147.523838] usb usb4: new device found, idVendor=0000, idProduct=0000 [ 147.523841] usb usb4: new device strings: Mfr=3, Product=2, SerialNumber=1 [ 147.523843] usb usb4: Product: UHCI Host Controller [ 147.523844] usb usb4: Manufacturer: Linux 2.6.19-rc5-mm1 uhci_hcd [ 147.523846] usb usb4: SerialNumber: 0000:00:1d.3 [ 147.523891] usb usb4: configuration #1 chosen from 1 choice [ 147.523910] hub 4-0:1.0: USB hub found [ 147.523914] hub 4-0:1.0: 2 ports detected [ 147.539333] GSI 18 (level, low) -> IRQ 18 [ 147.539390] PCI: Setting latency timer of device 0000:00:1d.2 to 64 [ 147.539394] uhci_hcd 0000:00:1d.2: UHCI Host Controller [ 147.539472] uhci_hcd 0000:00:1d.2: new USB bus registered, assigned bus number 5 [ 147.539558] uhci_hcd 0000:00:1d.2: irq 18, io base 0x0000e880 [ 147.539676] usb usb5: new device found, idVendor=0000, idProduct=0000 [ 147.539732] usb usb5: new device strings: Mfr=3, Product=2, SerialNumber=1 [ 147.539782] usb usb5: Product: UHCI Host Controller [ 147.539827] usb usb5: Manufacturer: Linux 2.6.19-rc5-mm1 uhci_hcd [ 147.539873] usb usb5: SerialNumber: 0000:00:1d.2 [ 147.539991] usb usb5: configuration #1 chosen from 1 choice [ 147.540055] hub 5-0:1.0: USB hub found [ 147.540101] hub 5-0:1.0: 2 ports detected [ 147.570396] ACPI: PCI Interrupt 0000:00:1b.0[A] -> GSI 19 (level, low) -> IRQ 19 [ 147.570540] PCI: Setting latency timer of device 0000:00:1b.0 to 64 [ 147.621303] hda_codec: Unknown model for ALC882, trying auto-probe from BIOS... [ 148.439518] usb 1-7: new high speed USB device using ehci_hcd and address 6 [ 148.501973] Adding 1959920k swap on /dev/sdc2. Priority:-1 extents:1 across:1959920k [ 148.554509] usb 1-7: new device found, idVendor=05e3, idProduct=0606 [ 148.554567] usb 1-7: new device strings: Mfr=0, Product=1, SerialNumber=0 [ 148.554614] usb 1-7: Product: USB2.0 Hub [ 148.554725] usb 1-7: configuration #1 chosen from 1 choice [ 148.555024] hub 1-7:1.0: USB hub found [ 148.555377] hub 1-7:1.0: 4 ports detected [ 148.760729] usb 2-1: new low speed USB device using uhci_hcd and address 2 [ 148.931995] usb 2-1: new device found, idVendor=045e, idProduct=001e [ 148.932043] usb 2-1: new device strings: Mfr=1, Product=2, SerialNumber=0 [ 148.932090] usb 2-1: Product: Microsoft IntelliMouse® Explorer [ 148.932135] usb 2-1: Manufacturer: Microsoft [ 148.932252] usb 2-1: configuration #1 chosen from 1 choice [ 149.097333] usb 2-2: new low speed USB device using uhci_hcd and address 3 [ 149.255606] usb 2-2: new device found, idVendor=0d3d, idProduct=0001 [ 149.255709] usb 2-2: new device strings: Mfr=0, Product=2, SerialNumber=0 [ 149.255812] usb 2-2: Product: USBPS2 [ 149.255970] usb 2-2: configuration #1 chosen from 1 choice [ 149.444210] i2c_adapter i2c-9191: ISA main adapter registered [ 149.448478] i2c-core: driver [eeprom] registered [ 149.448483] i2c_adapter i2c-0: found normal entry for adapter 0, addr 0x50 [ 149.448502] i801_smbus 0000:00:1f.3: Transaction (pre): CNT=00, CMD=30, ADD=a0, DAT0=78, DAT1=00 [ 149.450638] i801_smbus 0000:00:1f.3: Transaction (post): CNT=00, CMD=30, ADD=a0, DAT0=78, DAT1=00 [ 149.450656] i801_smbus 0000:00:1f.3: Transaction (pre): CNT=00, CMD=30, ADD=a0, DAT0=78, DAT1=00 [ 149.452677] i801_smbus 0000:00:1f.3: Transaction (post): CNT=00, CMD=30, ADD=a0, DAT0=78, DAT1=00 [ 149.452681] i2c_adapter i2c-0: client [eeprom] registered with bus id 0-0050 [ 149.452712] i2c_adapter i2c-0: found normal entry for adapter 0, addr 0x51 [ 149.452730] i801_smbus 0000:00:1f.3: Transaction (pre): CNT=00, CMD=30, ADD=a2, DAT0=78, DAT1=00 [ 149.454696] i801_smbus 0000:00:1f.3: Error: no response! [ 149.454715] i801_smbus 0000:00:1f.3: Transaction (post): CNT=00, CMD=30, ADD=a2, DAT0=78, DAT1=00 [ 149.454719] i2c_adapter i2c-0: found normal entry for adapter 0, addr 0x52 [ 149.454736] i801_smbus 0000:00:1f.3: Transaction (pre): CNT=00, CMD=30, ADD=a4, DAT0=78, DAT1=00 [ 149.456751] i801_smbus 0000:00:1f.3: Transaction (post): CNT=00, CMD=30, ADD=a4, DAT0=78, DAT1=00 [ 149.456769] i801_smbus 0000:00:1f.3: Transaction (pre): CNT=00, CMD=30, ADD=a4, DAT0=78, DAT1=00 [ 149.458788] i801_smbus 0000:00:1f.3: Transaction (post): CNT=00, CMD=30, ADD=a4, DAT0=78, DAT1=00 [ 149.458792] i2c_adapter i2c-0: client [eeprom] registered with bus id 0-0052 [ 149.458816] i2c_adapter i2c-0: found normal entry for adapter 0, addr 0x53 [ 149.458834] i801_smbus 0000:00:1f.3: Transaction (pre): CNT=00, CMD=30, ADD=a6, DAT0=78, DAT1=00 [ 149.460811] i801_smbus 0000:00:1f.3: Error: no response! [ 149.460830] i801_smbus 0000:00:1f.3: Transaction (post): CNT=00, CMD=30, ADD=a6, DAT0=78, DAT1=00 [ 149.460833] i2c_adapter i2c-0: found normal entry for adapter 0, addr 0x54 [ 149.460851] i801_smbus 0000:00:1f.3: Transaction (pre): CNT=00, CMD=30, ADD=a8, DAT0=78, DAT1=00 [ 149.462848] i801_smbus 0000:00:1f.3: Error: no response! [ 149.462866] i801_smbus 0000:00:1f.3: Transaction (post): CNT=00, CMD=30, ADD=a8, DAT0=78, DAT1=00 [ 149.462870] i2c_adapter i2c-0: found normal entry for adapter 0, addr 0x55 [ 149.462887] i801_smbus 0000:00:1f.3: Transaction (pre): CNT=00, CMD=30, ADD=aa, DAT0=78, DAT1=00 [ 149.464887] i801_smbus 0000:00:1f.3: Error: no response! [ 149.464907] i801_smbus 0000:00:1f.3: Transaction (post): CNT=00, CMD=30, ADD=aa, DAT0=78, DAT1=00 [ 149.464910] i2c_adapter i2c-0: found normal entry for adapter 0, addr 0x56 [ 149.464928] i801_smbus 0000:00:1f.3: Transaction (pre): CNT=00, CMD=30, ADD=ac, DAT0=78, DAT1=00 [ 149.466924] i801_smbus 0000:00:1f.3: Error: no response! [ 149.466943] i801_smbus 0000:00:1f.3: Transaction (post): CNT=00, CMD=30, ADD=ac, DAT0=78, DAT1=00 [ 149.466946] i2c_adapter i2c-0: found normal entry for adapter 0, addr 0x57 [ 149.466963] i801_smbus 0000:00:1f.3: Transaction (pre): CNT=00, CMD=30, ADD=ae, DAT0=78, DAT1=00 [ 149.468962] i801_smbus 0000:00:1f.3: Error: no response! [ 149.468980] i801_smbus 0000:00:1f.3: Transaction (post): CNT=00, CMD=30, ADD=ae, DAT0=78, DAT1=00 [ 149.484960] i2c_adapter i2c-9191: Driver w83627ehf registered [ 149.484968] i2c_adapter i2c-9191: client [w83627ehf] registered with bus id 9191-0290 [ 149.489348] Initializing USB Mass Storage driver... [ 149.540220] usb 5-1: new full speed USB device using uhci_hcd and address 2 [ 149.697140] usb 5-1: new device found, idVendor=07af, idProduct=0006 [ 149.697188] usb 5-1: new device strings: Mfr=1, Product=2, SerialNumber=0 [ 149.697236] usb 5-1: Product: DPCM-USB [ 149.697280] usb 5-1: Manufacturer: Microtech International, Inc [ 149.697417] usb 5-1: configuration #1 chosen from 1 choice [ 149.874425] usb 5-2: new full speed USB device using uhci_hcd and address 3 [ 150.184871] usb 1-7.3: new high speed USB device using ehci_hcd and address 7 [ 150.262165] usbcore: registered new interface driver hiddev [ 150.267647] usb 1-7.3: new device found, idVendor=0bda, idProduct=8187 [ 150.267697] usb 1-7.3: new device strings: Mfr=1, Product=2, SerialNumber=3 [ 150.267745] usb 1-7.3: Product: RTL8187_Wireless [ 150.267790] usb 1-7.3: Manufacturer: Manufacturer_Realtek_RTL8187_ [ 150.267837] usb 1-7.3: SerialNumber: 0015AF05C9DE [ 150.267964] usb 1-7.3: configuration #1 chosen from 1 choice [ 150.276515] input: Microsoft Microsoft IntelliMouse® Explorer as /class/input/input1 [ 150.276601] input: USB HID v1.00 Mouse [Microsoft Microsoft IntelliMouse® Explorer] on usb-0000:00:1d.0-1 [ 150.290540] input: USBPS2 as /class/input/input2 [ 150.290616] input: USB HID v1.00 Keyboard [USBPS2] on usb-0000:00:1d.0-2 [ 150.312537] input: USBPS2 as /class/input/input3 [ 150.312627] input: USB HID v1.00 Mouse [USBPS2] on usb-0000:00:1d.0-2 [ 150.312754] usbcore: registered new interface driver usbhid [ 150.312800] drivers/usb/input/hid-core.c: v2.6:USB HID core driver [ 150.313225] scsi5 : SCSI emulation for USB Mass Storage devices [ 150.313316] usb-storage: device found at 2 [ 150.313318] usb-storage: waiting for device to settle before scanning [ 150.313326] usbcore: registered new interface driver usb-storage [ 150.313374] USB Mass Storage support registered. [ 150.432062] ata2: exception Emask 0x10 SAct 0x0 SErr 0x4050002 action 0x2 frozen [ 150.432125] ata2: (irq_stat 0x00000040, connection status changed) [ 150.487257] reiser4: sda1: found disk format 4.0.0. [ 150.624672] logsave[1192]: segfault at 0000000000000000 rip 0000000000000000 rsp 00007fff96b7c278 error 4 [ 150.952806] ata2: waiting for device to spin up (8 secs) [ 151.513482] sky2 eth0: enabling interface [ 153.979191] sky2 eth0: Link is up at 1000 Mbps, full duplex, flow control both [ 155.050946] usb 5-2: new device found, idVendor=03f0, idProduct=0401 [ 155.051006] usb 5-2: new device strings: Mfr=1, Product=2, SerialNumber=3 [ 155.051054] usb 5-2: Product: HP ScanJet 5200C [ 155.051098] usb 5-2: Manufacturer: Hewlett-Packard [ 155.051143] usb 5-2: SerialNumber: SG91U161Z2HT [ 155.051279] usb 5-2: configuration #1 chosen from 1 choice [ 155.315660] scsi 5:0:0:0: Direct-Access ßßßßßßßß ßßßßßßßßßßßßßßßß X{s? PQ: 0 ANSI: 2 [ 155.330669] sd 5:0:0:0: Attached scsi removable disk sde [ 155.330749] sd 5:0:0:0: Attached scsi generic sg4 type 0 [ 155.331191] usb-storage: device scan complete [ 159.143855] ata2: soft resetting port [ 159.298902] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300) [ 165.583612] nvidia: module license 'NVIDIA' taints kernel. [ 165.839513] ACPI: PCI Interrupt 0000:04:00.0[A] -> GSI 16 (level, low) -> IRQ 16 [ 165.839526] PCI: Setting latency timer of device 0000:04:00.0 to 64 [ 165.839812] NVRM: loading NVIDIA Linux x86_64 Kernel Module 1.0-9629 Wed Nov 1 19:27:33 PST 2006 [ 166.246524] i2c_adapter i2c-1: adapter [NVIDIA i2c adapter 0 at 4:00.0] registered [ 166.246532] i2c_adapter i2c-1: found normal entry for adapter 1, addr 0x50 [ 166.246536] i2c_adapter i2c-1: found normal entry for adapter 1, addr 0x51 [ 166.246539] i2c_adapter i2c-1: found normal entry for adapter 1, addr 0x52 [ 166.246541] i2c_adapter i2c-1: found normal entry for adapter 1, addr 0x53 [ 166.246544] i2c_adapter i2c-1: found normal entry for adapter 1, addr 0x54 [ 166.246546] i2c_adapter i2c-1: found normal entry for adapter 1, addr 0x55 [ 166.246549] i2c_adapter i2c-1: found normal entry for adapter 1, addr 0x56 [ 166.246551] i2c_adapter i2c-1: found normal entry for adapter 1, addr 0x57 [ 166.246570] i2c_adapter i2c-2: adapter [NVIDIA i2c adapter 1 at 4:00.0] registered [ 166.246573] i2c_adapter i2c-2: found normal entry for adapter 2, addr 0x50 [ 166.246575] i2c_adapter i2c-2: found normal entry for adapter 2, addr 0x51 [ 166.246578] i2c_adapter i2c-2: found normal entry for adapter 2, addr 0x52 [ 166.246581] i2c_adapter i2c-2: found normal entry for adapter 2, addr 0x53 [ 166.246583] i2c_adapter i2c-2: found normal entry for adapter 2, addr 0x54 [ 166.246586] i2c_adapter i2c-2: found normal entry for adapter 2, addr 0x55 [ 166.246588] i2c_adapter i2c-2: found normal entry for adapter 2, addr 0x56 [ 166.246591] i2c_adapter i2c-2: found normal entry for adapter 2, addr 0x57 [ 166.246609] i2c_adapter i2c-3: adapter [NVIDIA i2c adapter 2 at 4:00.0] registered [ 166.246615] i2c_adapter i2c-3: found normal entry for adapter 3, addr 0x50 [ 166.246619] i2c_adapter i2c-3: found normal entry for adapter 3, addr 0x51 [ 166.246622] i2c_adapter i2c-3: found normal entry for adapter 3, addr 0x52 [ 166.246627] i2c_adapter i2c-3: found normal entry for adapter 3, addr 0x53 [ 166.246631] i2c_adapter i2c-3: found normal entry for adapter 3, addr 0x54 [ 166.246634] i2c_adapter i2c-3: found normal entry for adapter 3, addr 0x55 [ 166.246639] i2c_adapter i2c-3: found normal entry for adapter 3, addr 0x56 [ 166.246643] i2c_adapter i2c-3: found normal entry for adapter 3, addr 0x57 [ 189.264067] ata2.00: qc timeout (cmd 0xec) [ 189.264075] ata2.00: failed to IDENTIFY (I/O error, err_mask=0x104) [ 190.284155] ata2: hard resetting port [ 198.050132] ata2: port is slow to respond, please be patient (Status 0x80) [ 220.984721] ata2: port failed to respond (30 secs, Status 0x80) [ 220.984727] ata2: COMRESET failed (device not ready) [ 220.984731] ata2: hardreset failed, retrying in 5 secs [ 225.980360] ata2: hard resetting port [ 226.859646] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300) [ 226.859714] ata2.00: ATA-6, max UDMA/133, 640 sectors: LBA [ 226.859717] ata2.00: ata2: dev 0 multi count 1 [ 226.866670] ata2.00: configured for UDMA/133 [ 226.866678] ata2: EH complete [ 226.866914] scsi 2:0:0:0: Direct-Access ATA Config Disk RGL1 PQ: 0 ANSI: 5 [ 226.867060] SCSI device sdf: 640 512-byte hdwr sectors (0 MB) [ 226.867151] sdf: Write Protect is off [ 226.867154] sdf: Mode Sense: 00 3a 00 00 [ 226.867342] SCSI device sdf: drive cache: write through [ 226.867474] SCSI device sdf: 640 512-byte hdwr sectors (0 MB) [ 226.867564] sdf: Write Protect is off [ 226.867567] sdf: Mode Sense: 00 3a 00 00 [ 226.867737] SCSI device sdf: drive cache: write through [ 226.867740] sdf: unknown partition table [ 226.867951] sd 2:0:0:0: Attached scsi disk sdf [ 226.867985] sd 2:0:0:0: Attached scsi generic sg5 type 0 ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: 2.6.18 - AHCI detection pauses excessively 2006-11-15 18:22 ` Berck E. Nash @ 2006-11-23 11:20 ` JG 2006-11-27 3:35 ` Tejun Heo 1 sibling, 0 replies; 12+ messages in thread From: JG @ 2006-11-23 11:20 UTC (permalink / raw) To: linux-kernel [-- Attachment #1: Type: text/plain, Size: 797 bytes --] Hi, > Looks like you forgot to attach the patch, so I couldn't test it:) > Here's the section with the annoying hang with timing info. I > noticed that there are similar messages repeated later, but without > as much hang, so I've attached the entire dmesg as well, in case it's > of any help. any news on this? I didn't see the patch in 2.6.19-rc6-mm1, but maybe I overlooked it.. :) I'm currently using 2.6.19-rc6 and I have the same problem with my Asus P5W Deluxe mainboard (BIOS v1407). I have two disks attached, it seems detection fails on the SATA port where no disk is connected. BIOS is configured to use AHCI, kernel parameters are: kernel (hd0,0)/boot/2619rc6 init=/linuxrc root=/dev/ram0 rw hda=ide-cd mousepoll=1 attached: complete output of dmesg/messages and lspci -vv JG [-- Attachment #2: messages.gz --] [-- Type: application/x-gzip, Size: 7973 bytes --] [-- Attachment #3: lspci.gz --] [-- Type: application/x-gzip, Size: 2504 bytes --] ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: 2.6.18 - AHCI detection pauses excessively 2006-11-15 18:22 ` Berck E. Nash 2006-11-23 11:20 ` JG @ 2006-11-27 3:35 ` Tejun Heo 2006-11-27 8:58 ` Berck E. Nash 1 sibling, 1 reply; 12+ messages in thread From: Tejun Heo @ 2006-11-27 3:35 UTC (permalink / raw) To: Berck E. Nash; +Cc: linux-kernel@vger.kernel.org [-- Attachment #1: Type: text/plain, Size: 687 bytes --] On Wed, Nov 15, 2006 at 11:22:23AM -0700, Berck E. Nash wrote: > Tejun Heo wrote: > >Hmmm.. Can you try with the attached patch applied? Also, please turn > >on kernel config 'Kernel Hacking -> Show timing info on printks' and > >report boot dmesg. > > Looks like you forgot to attach the patch, so I couldn't test it:) > Here's the section with the annoying hang with timing info. I noticed > that there are similar messages repeated later, but without as much > hang, so I've attached the entire dmesg as well, in case it's of any help. Yeah, I did and forgot about this thread too. Sorry. This is on the top of my to-do list now. I'm attaching the patch. TIA. -- tejun [-- Attachment #2: patch --] [-- Type: text/plain, Size: 1472 bytes --] diff --git a/drivers/ata/libata-core.c b/drivers/ata/libata-core.c index 3fd7c79..89aa449 100644 --- a/drivers/ata/libata-core.c +++ b/drivers/ata/libata-core.c @@ -2669,20 +2669,26 @@ int sata_phy_debounce(struct ata_port *a /* DET stable? */ if (cur == last) { + printk("SATA PHY: stable DET=%x\n", cur); if (cur == 1 && time_before(jiffies, timeout)) continue; - if (time_after(jiffies, last_jiffies + duration)) + if (time_after(jiffies, last_jiffies + duration)) { + printk("SATA PHY: debounced\n"); return 0; + } continue; } + printk("SATA PHY: unstable DET=%x->%x\n", last, cur); /* unstable, start over */ last = cur; last_jiffies = jiffies; /* check timeout */ - if (time_after(jiffies, timeout)) + if (time_after(jiffies, timeout)) { + printk("SATA PHY: failed to debounce\n"); return -EBUSY; + } } } diff --git a/include/linux/libata.h b/include/linux/libata.h index 9080789..8220ca3 100644 --- a/include/linux/libata.h +++ b/include/linux/libata.h @@ -689,10 +689,11 @@ extern const struct ata_port_operations static inline const unsigned long * sata_ehc_deb_timing(struct ata_eh_context *ehc) { - if (ehc->i.flags & ATA_EHI_HOTPLUGGED) +/* if (ehc->i.flags & ATA_EHI_HOTPLUGGED) return sata_deb_timing_hotplug; else - return sata_deb_timing_normal; + return sata_deb_timing_normal;*/ + return sata_deb_timing_long; } static inline int ata_port_is_dummy(struct ata_port *ap) ^ permalink raw reply related [flat|nested] 12+ messages in thread
* Re: 2.6.18 - AHCI detection pauses excessively 2006-11-27 3:35 ` Tejun Heo @ 2006-11-27 8:58 ` Berck E. Nash 2006-11-29 8:55 ` Tejun Heo 0 siblings, 1 reply; 12+ messages in thread From: Berck E. Nash @ 2006-11-27 8:58 UTC (permalink / raw) To: Tejun Heo; +Cc: linux-kernel@vger.kernel.org [-- Attachment #1: Type: text/plain, Size: 368 bytes --] Tejun Heo wrote: > Yeah, I did and forgot about this thread too. Sorry. This is on the > top of my to-do list now. I'm attaching the patch. TIA. That didn't fix the problem, but did change the messages. I've attached the entire log, including the weird errors on power-off from the same device that gives problems on boot, which I suspect are related. Berck [-- Attachment #2: ahcilog --] [-- Type: text/plain, Size: 42907 bytes --] [ 0.000000] Linux version 2.6.19-rc6-mm1 (root@luna) (gcc version 4.1.2 20061115 (prerelease) (Debian 4.1.1-20)) #3 SMP PREEMPT Sun Nov 26 21:25:59 MST 2006 [ 0.000000] Command line: root=/dev/sdc1 ro console=tty0 console=ttyS0,115200n8 BOOT_IMAGE=vmlinuz [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: 0000000000000000 - 000000000009fc00 (usable) [ 0.000000] BIOS-e820: 000000000009fc00 - 00000000000a0000 (reserved) [ 0.000000] BIOS-e820: 00000000000e4000 - 0000000000100000 (reserved) [ 0.000000] BIOS-e820: 0000000000100000 - 000000003ff80000 (usable) [ 0.000000] BIOS-e820: 000000003ff80000 - 000000003ff8e000 (ACPI data) [ 0.000000] BIOS-e820: 000000003ff8e000 - 000000003ffe0000 (ACPI NVS) [ 0.000000] BIOS-e820: 000000003ffe0000 - 0000000040000000 (reserved) [ 0.000000] BIOS-e820: 00000000ffb00000 - 0000000100000000 (reserved) [ 0.000000] end_pfn_map = 1048576 [ 0.000000] DMI 2.4 present. [ 0.000000] Zone PFN ranges: [ 0.000000] DMA 0 -> 4096 [ 0.000000] DMA32 4096 -> 1048576 [ 0.000000] Normal 1048576 -> 1048576 [ 0.000000] early_node_map[2] active PFN ranges [ 0.000000] 0: 0 -> 159 [ 0.000000] 0: 256 -> 262016 [ 0.000000] ACPI: PM-Timer IO Port: 0x808 [ 0.000000] ACPI: LAPIC (acpi_id[0x01] lapic_id[0x00] enabled) [ 0.000000] Processor #0 (Bootup-CPU) [ 0.000000] ACPI: LAPIC (acpi_id[0x02] lapic_id[0x01] enabled) [ 0.000000] Processor #1 [ 0.000000] ACPI: LAPIC (acpi_id[0x03] lapic_id[0x82] disabled) [ 0.000000] ACPI: LAPIC (acpi_id[0x04] lapic_id[0x83] disabled) [ 0.000000] ACPI: IOAPIC (id[0x02] address[0xfec00000] gsi_base[0]) [ 0.000000] IOAPIC[0]: apic_id 2, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] Setting APIC routing to flat [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] Nosave address range: 000000000009f000 - 00000000000a0000 [ 0.000000] Nosave address range: 00000000000a0000 - 00000000000e4000 [ 0.000000] Nosave address range: 00000000000e4000 - 0000000000100000 [ 0.000000] Allocating PCI resources starting at 50000000 (gap: 40000000:bfb00000) [ 0.000000] PERCPU: Allocating 32512 bytes of per cpu data [ 0.000000] Built 1 zonelists. Total pages: 257375 [ 0.000000] Kernel command line: root=/dev/sdc1 ro console=tty0 console=ttyS0,115200n8 BOOT_IMAGE=vmlinuz [ 0.000000] Initializing CPU#0 [ 0.000000] PID hash table entries: 4096 (order: 12, 32768 bytes) [ 57.369381] Console: colour VGA+ 80x25 [ 57.632610] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes) [ 57.639997] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes) [ 57.646956] Checking aperture... [ 57.657752] Memory: 1027700k/1048064k available (2281k kernel code, 19860k reserved, 999k data, 196k init) [ 57.726521] Calibrating delay using timer specific routine.. 5800.15 BogoMIPS (lpj=2900075) [ 57.734992] Mount-cache hash table entries: 256 [ 57.739636] CPU: L1 I cache: 32K, L1 D cache: 32K [ 57.744433] CPU: L2 cache: 2048K [ 57.747699] using mwait in idle threads. [ 57.751657] CPU: Physical Processor ID: 0 [ 57.755701] CPU: Processor Core ID: 0 [ 57.759400] CPU0: Thermal monitoring enabled (TM2) [ 57.764238] Freeing SMP alternatives: 24k freed [ 57.768811] ACPI: Core revision 20060707 [ 57.797724] Using local APIC timer interrupts. [ 57.836680] result 25877185 [ 57.839512] Detected 25.877 MHz APIC timer. [ 57.844463] Booting processor 1/2 APIC 0x1 [ 57.858937] Initializing CPU#1 [ 57.919341] Calibrating delay using timer specific routine.. 5796.44 BogoMIPS (lpj=2898222) [ 57.919345] CPU: L1 I cache: 32K, L1 D cache: 32K [ 57.919346] CPU: L2 cache: 2048K [ 57.919348] CPU: Physical Processor ID: 0 [ 57.919348] CPU: Processor Core ID: 1 [ 57.919352] CPU1: Thermal monitoring enabled (TM2) [ 57.919543] Intel(R) Core(TM)2 CPU 6300 @ 1.86GHz stepping 06 [ 57.920346] Brought up 2 CPUs [ 57.962055] testing NMI watchdog ... OK. [ 57.996481] time.c: Using 14.318180 MHz WALL HPET GTOD HPET/TSC timer. [ 58.003041] time.c: Detected 2898.247 MHz processor. [ 58.095698] migration_cost=22 [ 58.099005] NET: Registered protocol family 16 [ 58.103489] wait_for_probes: waiting for 0 threads [ 58.108353] wait_for_probes: waiting for 0 threads [ 58.113184] ACPI: bus type pci registered [ 58.117236] PCI: BIOS Bug: MCFG area at f0000000 is not E820-reserved [ 58.123713] PCI: Not using MMCONFIG. [ 58.127328] PCI: Using configuration type 1 [ 58.131544] wait_for_probes: waiting for 0 threads [ 58.144443] ACPI: Interpreter enabled [ 58.148145] ACPI: Using IOAPIC for interrupt routing [ 58.153867] ACPI: PCI Root Bridge [PCI0] (0000:00) [ 58.159174] PCI quirk: region 0800-087f claimed by ICH6 ACPI/GPIO/TCO [ 58.165654] PCI quirk: region 0480-04bf claimed by ICH6 GPIO [ 58.171805] PCI: Transparent bridge - 0000:00:1e.0 [ 58.183676] ACPI: PCI Interrupt Link [LNKA] (IRQs 3 4 5 6 7 10 *11 12 14 15) [ 58.191454] ACPI: PCI Interrupt Link [LNKB] (IRQs 3 4 5 6 *7 10 11 12 14 15) [ 58.199230] ACPI: PCI Interrupt Link [LNKC] (IRQs *3 4 5 6 7 10 11 12 14 15) [ 58.207003] ACPI: PCI Interrupt Link [LNKD] (IRQs 3 4 5 6 7 *10 11 12 14 15) [ 58.214779] ACPI: PCI Interrupt Link [LNKE] (IRQs 3 4 *5 6 7 10 11 12 14 15) [ 58.222892] ACPI: PCI Interrupt Link [LNKF] (IRQs 3 4 5 6 7 10 *11 12 14 15) [ 58.230668] ACPI: PCI Interrupt Link [LNKG] (IRQs 3 4 *5 6 7 10 11 12 14 15) [ 58.238444] ACPI: PCI Interrupt Link [LNKH] (IRQs 3 4 5 6 7 *10 11 12 14 15) [ 58.246113] Linux Plug and Play Support v0.97 (c) Adam Belay [ 58.251804] pnp: PnP ACPI init [ 58.257367] pnp: PnP ACPI: found 15 devices [ 58.261613] intel_rng: FWH not detected [ 58.265571] SCSI subsystem initialized [ 58.269400] PCI: Using ACPI for IRQ routing [ 58.273619] PCI: If a device doesn't work, try "pci=routeirq". If it helps, post a report [ 58.281970] wait_for_probes: waiting for 0 threads [ 58.286792] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 58.291874] hpet0: 3 64-bit timers, 14318180 Hz [ 58.297442] PCI-GART: No AMD northbridge found. [ 58.302523] pnp: 00:07: ioport range 0x290-0x297 has been reserved [ 58.308910] PCI: Bridge: 0000:00:01.0 [ 58.312610] IO window: disabled. [ 58.316047] MEM window: faa00000-feafffff [ 58.320263] PREFETCH window: cff00000-efefffff [ 58.324915] PCI: Bridge: 0000:00:1c.0 [ 58.328610] IO window: disabled. [ 58.332050] MEM window: disabled. [ 58.335573] PREFETCH window: cfe00000-cfefffff [ 58.340226] PCI: Bridge: 0000:00:1c.3 [ 58.343919] IO window: c000-cfff [ 58.347359] MEM window: fa900000-fa9fffff [ 58.351575] PREFETCH window: disabled. [ 58.355533] PCI: Bridge: 0000:00:1e.0 [ 58.359229] IO window: b000-bfff [ 58.362668] MEM window: fa700000-fa8fffff [ 58.366885] PREFETCH window: 50000000-500fffff [ 58.371541] ACPI: PCI Interrupt 0000:00:01.0[A] -> GSI 16 (level, low) -> IRQ 16 [ 58.379035] ACPI: PCI Interrupt 0000:00:1c.0[A] -> GSI 16 (level, low) -> IRQ 16 [ 58.386523] ACPI: PCI Interrupt 0000:00:1c.3[D] -> GSI 19 (level, low) -> IRQ 19 [ 58.394027] NET: Registered protocol family 2 [ 58.410079] IP route cache hash table entries: 32768 (order: 6, 262144 bytes) [ 58.417339] TCP established hash table entries: 131072 (order: 9, 2097152 bytes) [ 58.425423] TCP bind hash table entries: 65536 (order: 8, 1048576 bytes) [ 58.432657] TCP: Hash tables configured (established 131072 bind 65536) [ 58.439300] TCP reno registered [ 58.446108] wait_for_probes: waiting for 0 threads [ 58.451398] audit: initializing netlink socket (disabled) [ 58.456838] audit(1164581690.592:1): initialized [ 58.466875] Loading Reiser4. See www.namesys.com for a description of Reiser4. [ 58.474192] io scheduler noop registered [ 58.478542] io scheduler anticipatory registered (default) [ 58.484336] assign_interrupt_mode Found MSI capability [ 58.489590] assign_interrupt_mode Found MSI capability [ 58.494852] assign_interrupt_mode Found MSI capability [ 58.500163] input: Power Button (FF) as /class/input/input0 [ 58.505766] ACPI: Power Button (FF) [PWRF] [ 58.509935] input: Power Button (CM) as /class/input/input1 [ 58.515541] ACPI: Power Button (CM) [PWRB] [ 58.519974] ACPI: Processor [CPU1] (supports 8 throttling states) [ 58.526417] ACPI: Processor [CPU2] (supports 8 throttling states) [ 58.532636] ACPI: Getting cpuindex for acpiid 0x3 [ 58.537377] ACPI: Getting cpuindex for acpiid 0x4 [ 58.543441] Real Time Clock Driver v1.12ac [ 58.547651] Linux agpgart interface v0.101 (c) Dave Jones [ 58.553087] Serial: 8250/16550 driver $Revision: 1.90 $ 4 ports, IRQ sharing disabled [ 58.561039] serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A [ 58.567369] 00:0c: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A [ 58.573106] Uniform Multi-Platform E-IDE driver Revision: 7.00alpha2 [ 58.579491] ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx [ 58.587557] ICH7: IDE controller at PCI slot 0000:00:1f.1 [ 58.592994] ACPI: PCI Interrupt 0000:00:1f.1[A] -> GSI 22 (level, low) -> IRQ 22 [ 58.600476] ICH7: chipset revision 1 [ 58.604083] ICH7: not 100% native mode: will probe irqs later [ 58.609868] ide0: BM-DMA at 0xffa0-0xffa7, BIOS settings: hda:DMA, hdb:DMA [ 58.617226] ide1: BM-DMA at 0xffa8-0xffaf, BIOS settings: hdc:pio, hdd:pio<7>Losing some ticks... checking if CPU frequency changed. [ 58.629616] [ 59.303006] hda: LITE-ON LTR-48246S, ATAPI CD/DVD-ROM drive [ 60.022548] hdb: _NEC DVD_RW ND-3520AW, ATAPI CD/DVD-ROM drive [ 60.082411] ide0 at 0x1f0-0x1f7,0x3f6 on irq 14 [ 60.605720] SiI680: IDE controller at PCI slot 0000:01:00.0 [ 60.611332] ACPI: PCI Interrupt 0000:01:00.0[A] -> GSI 21 (level, low) -> IRQ 21 [ 60.618815] SiI680: chipset revision 2 [ 60.622608] SiI680: BASE CLOCK == 133 [ 60.626351] SiI680: 100% native mode on irq 21 [ 60.630835] ide2: MMIO-DMA , BIOS settings: hde:pio, hdf:pio [ 60.636968] ide3: MMIO-DMA , BIOS settings: hdg:pio, hdh:pio [ 60.908838] hde: SAMSUNG WN316025A (1.6 GB), ATA DISK drive [ 61.525676] ide2 at 0xffffc20000006c80-0xffffc20000006c87,0xffffc20000006c8a on irq 21 [ 61.797585] hdg: MAXTOR 6L040J2, ATA DISK drive [ 62.413451] ide3 at 0xffffc20000006cc0-0xffffc20000006cc7,0xffffc20000006cca on irq 21 [ 62.421565] hde: max request size: 64KiB [ 62.425521] hde: 3145968 sectors (1610 MB) w/109KiB Cache, CHS=3121/16/63, DMA [ 62.432984] hde: hde1 [ 62.448439] hdg: max request size: 64KiB [ 62.453350] hdg: 78198750 sectors (40037 MB) w/1819KiB Cache, CHS=65535/16/63, UDMA(133) [ 62.461826] hdg: cache flushes supported [ 62.465792] hdg: hdg1 [ 62.484633] hda: ATAPI 48X CD-ROM CD-R/RW drive, 2048kB Cache, UDMA(33) [ 62.491607] Uniform CD-ROM driver Revision: 3.20 [ 62.535733] hdb: ATAPI 48X DVD-ROM DVD-R CD-R/RW drive, 2048kB Cache, UDMA(33) [ 62.556615] ACPI: PCI Interrupt 0000:01:01.0[A] -> GSI 22 (level, low) -> IRQ 22 [ 62.564736] ACPI: PCI Interrupt 0000:00:1f.2[B] -> GSI 23 (level, low) -> IRQ 23 [ 62.572472] PNP: PS/2 Controller [PNP0303:PS2K] at 0x60,0x64 irq 1 [ 62.578688] PNP: PS/2 controller doesn't have AUX irq; using default 12 [ 62.587929] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 62.592943] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 62.598095] mice: PS/2 mouse device common for all mice [ 62.603362] EDAC MC: Ver: 2.0.1 Nov 25 2006 [ 62.607686] TCP cubic registered [ 62.610950] Initializing XFRM netlink socket [ 62.615263] NET: Registered protocol family 1 [ 62.619657] NET: Registered protocol family 17 [ 62.624147] NET: Registered protocol family 15 [ 62.628628] wait_for_probes: waiting for 3 threads [ 62.636844] input: AT Translated Set 2 keyboard as /class/input/input2 [ 62.773700] scsi0 : Adaptec AIC7XXX EISA/VLB/PCI SCSI HBA DRIVER, Rev 7.0 [ 62.773701] <Adaptec 2940 Ultra2 SCSI adapter> [ 62.773702] aic7890/91: Ultra2 Wide Channel A, SCSI Id=7, 32/253 SCBs [ 62.773702] [ 63.054114] scsi 0:0:1:0: Direct-Access IBM-PCCO ST39102LC !# B219 PQ: 0 ANSI: 2 [ 63.062248] scsi0:A:1:0: Tagged Queuing enabled. Depth 8 [ 63.067731] target0:0:1: Beginning Domain Validation [ 63.079230] target0:0:1: wide asynchronous [ 63.088137] target0:0:1: FAST-40 WIDE SCSI 80.0 MB/s ST (25 ns, offset 15) [ 63.099356] target0:0:1: Domain Validation skipping write tests [ 63.105399] target0:0:1: Ending Domain Validation [ 63.113209] scsi 0:0:2:0: Direct-Access SGI SEAGATE ST39102L 2702 PQ: 0 ANSI: 2 [ 63.121334] scsi0:A:2:0: Tagged Queuing enabled. Depth 8 [ 63.126818] target0:0:2: Beginning Domain Validation [ 63.137168] target0:0:2: wide asynchronous [ 63.145241] target0:0:2: FAST-40 WIDE SCSI 80.0 MB/s ST (25 ns, offset 15) [ 63.155644] target0:0:2: Domain Validation skipping write tests [ 63.161682] target0:0:2: Ending Domain Validation [ 63.577105] ahci 0000:00:1f.2: AHCI 0001.0100 32 slots 4 ports 3 Gbps 0xf impl SATA mode [ 63.585232] ahci 0000:00:1f.2: flags: 64bit ncq pm led clo pio slum part [ 63.592092] ata1: SATA max UDMA/133 cmd 0xFFFFC2000000E900 ctl 0x0 bmdma 0x0 irq 316 [ 63.599913] ata2: SATA max UDMA/133 cmd 0xFFFFC2000000E980 ctl 0x0 bmdma 0x0 irq 316 [ 63.607731] ata3: SATA max UDMA/133 cmd 0xFFFFC2000000EA00 ctl 0x0 bmdma 0x0 irq 316 [ 63.615549] ata4: SATA max UDMA/133 cmd 0xFFFFC2000000EA80 ctl 0x0 bmdma 0x0 irq 316 [ 63.623332] scsi1 : ahci [ 63.927590] SATA PHY: stable DET=3 [ 64.031995] SATA PHY: stable DET=3 [ 64.136570] SATA PHY: stable DET=3 [ 64.241067] SATA PHY: stable DET=3 [ 64.344525] SATA PHY: stable DET=3 [ 64.449101] SATA PHY: stable DET=3 [ 64.553506] SATA PHY: stable DET=3 [ 64.658081] SATA PHY: stable DET=3 [ 64.762552] SATA PHY: stable DET=3 [ 64.866036] SATA PHY: stable DET=3 [ 64.970612] SATA PHY: stable DET=3 [ 65.075017] SATA PHY: stable DET=3 [ 65.179592] SATA PHY: stable DET=3 [ 65.284037] SATA PHY: stable DET=3 [ 65.387534] SATA PHY: stable DET=3 [ 65.492109] SATA PHY: stable DET=3 [ 65.596515] SATA PHY: stable DET=3 [ 65.701089] SATA PHY: stable DET=3 [ 65.805534] SATA PHY: stable DET=3 [ 65.909045] SATA PHY: stable DET=3 [ 65.912479] SATA PHY: debounced [ 66.070326] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300) [ 66.083463] ata1.00: ATA-6, max UDMA/133, 72303840 sectors: LBA48 [ 66.089681] ata1.00: ata1: dev 0 multi count 16 [ 66.102173] ata1.00: configured for UDMA/133 [ 66.106487] scsi2 : ahci [ 66.240954] SCSI device sda: 17774160 512-byte hdwr sectors (9100 MB) [ 66.249392] sda: Write Protect is off [ 66.254682] SCSI device sda: write cache: enabled, read cache: enabled, supports DPO and FUA [ 66.263935] SCSI device sda: 17774160 512-byte hdwr sectors (9100 MB) [ 66.272374] sda: Write Protect is off [ 66.277646] SCSI device sda: write cache: enabled, read cache: enabled, supports DPO and FUA [ 66.286123] sda: sda1 sda2 [ 66.295437] sd 0:0:1:0: Attached scsi disk sda [ 66.299945] sd 0:0:1:0: Attached scsi generic sg0 type 0 [ 66.306160] SCSI device sdb: 17781520 512-byte hdwr sectors (9104 MB) [ 66.316003] sdb: Write Protect is off [ 66.323489] SCSI device sdb: write cache: enabled, read cache: enabled, supports DPO and FUA [ 66.332780] SCSI device sdb: 17781520 512-byte hdwr sectors (9104 MB) [ 66.342624] sdb: Write Protect is off [ 66.350085] SCSI device sdb: write cache: enabled, read cache: enabled, supports DPO and FUA [ 66.358564] sdb: sdb1 [ 66.367085] sd 0:0:2:0: Attached scsi disk sdb [ 66.371597] sd 0:0:2:0: Attached scsi generic sg1 type 0 [ 66.413576] SATA PHY: stable DET=3 [ 66.518137] SATA PHY: stable DET=3 [ 66.622543] SATA PHY: stable DET=3 [ 66.727118] SATA PHY: stable DET=3 [ 66.831523] SATA PHY: stable DET=3 [ 66.936098] SATA PHY: stable DET=3 [ 67.040660] SATA PHY: stable DET=3 [ 67.145065] SATA PHY: stable DET=3 [ 67.249640] SATA PHY: stable DET=3 [ 67.354046] SATA PHY: stable DET=3 [ 67.458621] SATA PHY: stable DET=3 [ 67.563183] SATA PHY: stable DET=3 [ 67.667589] SATA PHY: stable DET=3 [ 67.772164] SATA PHY: stable DET=3 [ 67.876570] SATA PHY: stable DET=3 [ 67.981144] SATA PHY: stable DET=3 [ 68.085707] SATA PHY: stable DET=3 [ 68.190099] SATA PHY: stable DET=3 [ 68.294674] SATA PHY: stable DET=3 [ 68.404075] SATA PHY: stable DET=3 [ 68.407512] SATA PHY: debounced [ 68.565486] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300) [ 98.544548] ata2.00: qc timeout (cmd 0xec) [ 98.548679] ata2.00: failed to IDENTIFY (I/O error, err_mask=0x104) [ 99.358514] SATA PHY: stable DET=3 [ 99.463089] SATA PHY: stable DET=3 [ 99.567495] SATA PHY: stable DET=3 [ 99.672070] SATA PHY: stable DET=3 [ 99.776515] SATA PHY: stable DET=3 [ 99.880026] SATA PHY: stable DET=3 [ 99.984601] SATA PHY: stable DET=3 [ 100.089006] SATA PHY: stable DET=3 [ 100.193581] SATA PHY: stable DET=3 [ 100.298013] SATA PHY: stable DET=3 [ 100.401537] SATA PHY: stable DET=3 [ 100.506112] SATA PHY: stable DET=3 [ 100.610517] SATA PHY: stable DET=3 [ 100.715092] SATA PHY: stable DET=3 [ 100.819511] SATA PHY: stable DET=3 [ 100.924060] SATA PHY: stable DET=3 [ 101.028635] SATA PHY: stable DET=3 [ 101.133040] SATA PHY: stable DET=3 [ 101.237615] SATA PHY: stable DET=3 [ 101.342034] SATA PHY: stable DET=3 [ 101.345474] SATA PHY: debounced [ 108.385331] ata2: port is slow to respond, please be patient (Status 0x80) [ 131.326177] ata2: port failed to respond (30 secs, Status 0x80) [ 131.332131] ata2: COMRESET failed (device not ready) [ 131.337127] ata2: hardreset failed, retrying in 5 secs [ 136.642653] SATA PHY: stable DET=3 [ 136.747228] SATA PHY: stable DET=3 [ 136.851699] SATA PHY: stable DET=3 [ 136.955170] SATA PHY: stable DET=3 [ 137.059746] SATA PHY: stable DET=3 [ 137.164151] SATA PHY: stable DET=3 [ 137.268726] SATA PHY: stable DET=3 [ 137.373184] SATA PHY: stable DET=3 [ 137.476682] SATA PHY: stable DET=3 [ 137.581257] SATA PHY: stable DET=3 [ 137.685662] SATA PHY: stable DET=3 [ 137.790237] SATA PHY: stable DET=3 [ 137.894682] SATA PHY: stable DET=3 [ 137.998193] SATA PHY: stable DET=3 [ 138.102768] SATA PHY: stable DET=3 [ 138.207173] SATA PHY: stable DET=3 [ 138.311748] SATA PHY: stable DET=3 [ 138.416180] SATA PHY: stable DET=3 [ 138.519704] SATA PHY: stable DET=3 [ 138.624279] SATA PHY: stable DET=3 [ 138.627716] SATA PHY: debounced [ 138.630908] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300) [ 138.641746] ata2.00: ATA-6, max UDMA/133, 640 sectors: LBA [ 138.647349] ata2.00: ata2: dev 0 multi count 1 [ 138.656446] ata2.00: configured for UDMA/133 [ 138.660753] scsi3 : ahci [ 138.964628] SATA PHY: stable DET=3 [ 139.069190] SATA PHY: stable DET=3 [ 139.173752] SATA PHY: stable DET=3 [ 139.278157] SATA PHY: stable DET=3 [ 139.382733] SATA PHY: stable DET=3 [ 139.487138] SATA PHY: stable DET=3 [ 139.591713] SATA PHY: stable DET=3 [ 139.696275] SATA PHY: stable DET=3 [ 139.800681] SATA PHY: stable DET=3 [ 139.905256] SATA PHY: stable DET=3 [ 140.009661] SATA PHY: stable DET=3 [ 140.114237] SATA PHY: stable DET=3 [ 140.218799] SATA PHY: stable DET=3 [ 140.323204] SATA PHY: stable DET=3 [ 140.427779] SATA PHY: stable DET=3 [ 140.532185] SATA PHY: stable DET=3 [ 140.636760] SATA PHY: stable DET=3 [ 140.741322] SATA PHY: stable DET=3 [ 140.845727] SATA PHY: stable DET=3 [ 140.950302] SATA PHY: stable DET=3 [ 140.953737] SATA PHY: debounced [ 141.111543] ata3: SATA link up 1.5 Gbps (SStatus 113 SControl 300) [ 141.123065] ata3.00: ATA-7, max UDMA/133, 488397168 sectors: LBA48 NCQ (depth 31/32) [ 141.130844] ata3.00: ata3: dev 0 multi count 16 [ 141.140769] ata3.00: configured for UDMA/133 [ 141.145078] scsi4 : ahci [ 141.449052] SATA PHY: stable DET=0 [ 141.553626] SATA PHY: stable DET=0 [ 141.658032] SATA PHY: stable DET=0 [ 141.762607] SATA PHY: stable DET=0 [ 141.867052] SATA PHY: stable DET=0 [ 141.970563] SATA PHY: stable DET=0 [ 142.075138] SATA PHY: stable DET=0 [ 142.179543] SATA PHY: stable DET=0 [ 142.284118] SATA PHY: stable DET=0 [ 142.388550] SATA PHY: stable DET=0 [ 142.492074] SATA PHY: stable DET=0 [ 142.596649] SATA PHY: stable DET=0 [ 142.701048] SATA PHY: stable DET=0 [ 142.805617] SATA PHY: stable DET=0 [ 142.910022] SATA PHY: stable DET=0 [ 143.014584] SATA PHY: stable DET=0 [ 143.119146] SATA PHY: stable DET=0 [ 143.223552] SATA PHY: stable DET=0 [ 143.328127] SATA PHY: stable DET=0 [ 143.432532] SATA PHY: stable DET=0 [ 143.435965] SATA PHY: debounced [ 143.439146] ata4: SATA link down (SStatus 0 SControl 300) [ 143.444617] scsi 1:0:0:0: Direct-Access ATA WDC WD360GD-00FL 31.0 PQ: 0 ANSI: 5 [ 143.452786] SCSI device sdc: 72303840 512-byte hdwr sectors (37020 MB) [ 143.459353] sdc: Write Protect is off [ 143.463061] SCSI device sdc: write cache: enabled, read cache: enabled, doesn't support DPO or FUA [ 143.472081] SCSI device sdc: 72303840 512-byte hdwr sectors (37020 MB) [ 143.478649] sdc: Write Protect is off [ 143.482352] SCSI device sdc: write cache: enabled, read cache: enabled, doesn't support DPO or FUA [ 143.491347] sdc: sdc1 sdc2 [ 143.502458] sd 1:0:0:0: Attached scsi disk sdc [ 143.506968] sd 1:0:0:0: Attached scsi generic sg2 type 0 [ 143.512352] scsi 2:0:0:0: Direct-Access ATA Config Disk RGL1 PQ: 0 ANSI: 5 [ 143.520525] SCSI device sdd: 640 512-byte hdwr sectors (0 MB) [ 143.526313] sdd: Write Protect is off [ 143.530021] SCSI device sdd: write cache: disabled, read cache: enabled, doesn't support DPO or FUA [ 143.539123] SCSI device sdd: 640 512-byte hdwr sectors (0 MB) [ 143.544915] sdd: Write Protect is off [ 143.548618] SCSI device sdd: write cache: disabled, read cache: enabled, doesn't support DPO or FUA [ 143.557700] sdd: unknown partition table [ 143.561965] sd 2:0:0:0: Attached scsi disk sdd [ 143.566471] sd 2:0:0:0: Attached scsi generic sg3 type 0 [ 143.571856] scsi 3:0:0:0: Direct-Access ATA ST3250823AS 3.03 PQ: 0 ANSI: 5 [ 143.580033] SCSI device sde: 488397168 512-byte hdwr sectors (250059 MB) [ 143.586770] sde: Write Protect is off [ 143.590476] SCSI device sde: write cache: enabled, read cache: enabled, doesn't support DPO or FUA [ 143.599487] SCSI device sde: 488397168 512-byte hdwr sectors (250059 MB) [ 143.606226] sde: Write Protect is off [ 143.609938] SCSI device sde: write cache: enabled, read cache: enabled, doesn't support DPO or FUA [ 143.618935] sde: sde1 sde2 [ 143.628705] sd 3:0:0:0: Attached scsi disk sde [ 143.633214] sd 3:0:0:0: Attached scsi generic sg4 type 0 [ 143.638621] wait_for_probes: waiting for 0 threads [ 143.644027] reiser4: sdc1: found disk format 4.0.0. [ 144.852704] VFS: Mounted root (reiser4 filesystem) readonly. [ 144.858424] Freeing unused kernel memory: 196k freed INIT: version 2.86 booting Starting the hotplug events dispatcher: udevd. Synthesizing the initial hotplug events...done. Waiting for /dev to be fully populated...[ 147.094500] ACPI: PCI Interrupt 0000:02:00.0[A] -> GSI 19 (level, low) -> IRQ 19 [ 147.102175] sky2 v1.10 addr 0xfa9fc000 irq 19 Yukon-EC (0xb6) rev 2 [ 147.108722] sky2 eth0: addr 00:18:f3:3d:1b:06 [ 147.113659] Floppy drive(s): fd0 is 1.44M [ 147.132226] FDC 0 is a post-1991 82077 [ 147.140641] usbcore: registered new interface driver usbfs [ 147.146253] usbcore: registr4en1ew interface driver hub [ 147.151727] usbcore: registered new device driver usb [ 147.176300] ACPI: PCI Interrupt 0000:00:1f.3[B] -> GSI 23 (level, low) -> IRQ 23 [ 147.194214] USB Universal Host Controller Interface driver v3.0 [ 147.200314] ACPI: PCI Interrupt 0000:00:1d.0[A] -> GSI 20 (level, low) -> IRQ 20 [ 147.205440] ACPI: PCI Interrupt 000070:1d.1[B] -> GSI 17 (level, low) -> IRQ 17 [ 147.205450] uhci_hcd 0000:00:1d.1: UHCI Host Controller [ 147.205525] uhci_hcd 0000:00:1d.1: new USB bus registered, assigned bus number 1 [ 147.2054P] uhci_hcd 0000:00:1d.1: irq 17, io base 0x0000e800 [ 147.206118] ACPI: PCI Interrupt 0000:00:1d.2[C] -> GSI 18 (level, low) -> IRQ 18 [ 147.206126] uhci_hcd 0000:00:1d.2: UHCI Hosodnraoeir [ 147.206158] usb usb1: new device found, idVendor=0000, idProduct=0000 [ 147.206159] usb usb1: new device strings: Mfr=3, Product=2, SerialNumber=1 [ 147.206161] usb usb1: Product: UHCI Host ContrlUer [ 147.206162] usb usb1: Manufacturer: Linux 2.6.19-rc6-mm1 uhci_hcd [ 147.206163] usb usb1: SerialNumber: 0000:00:1d.1 [ 147.206204] usb usb1: configuration #1 chosen fro 21 choice [ 147.206218] hub 1-0:1.0: USB hub found [ 147.206221] hub 1-0:1.0: 2 ports detected [ 147.206233] uhci_hcd 0000:00:1d.2: new USB bus registered, assigned bus number 2 [ 147.206261] uhci_hcd 0000:00:1d.2: irq 18, io base 0x0000e880 [ 147.206292] ACPI: PCI Interrupt 0000:00:1d.3[D] -> GSI 19 (level, low) -> IRQ 19 [ 147.206299] uhci_hcd 0000:00:1d.3: UHCI Host Controller [ 147.206320] usb usb2: new device found, idVendor=0000, idProduct=0000 [ 147.206322] usb usb2: new device strings: Mfr=3, Product=2, SerialNumber=1 [ 147.206323] usb usb2: Product: UHCI Host Controller [ 147.206324] usb usb2: Manufacturer: Linux 2.6.19-rc6-mm1 uhci_hcd [ 147.206326] usb usb2: SerialNumber: 0000:00:1d.2 [ 147.206354] usb usb2: configuration #1 chosen from 1 choice [ 147.206367] hub 2-0:1.0: USB hub found [ 147.206370] hub 2-0:1.0: 2 ports detected [ 147.206382] uhci_hcd 0000:00:1d.3: new USB bus registered, assigned bus number 3 [ 147.206408] uhci_hcd 0000:00:1d.3: irq 19, io base 0x0000ec00 [ 147.206446] usb usb3: new device found, idVendor=0000, idProduct=0000 [ 147.206447] usb usb3: new device strings: Mfr=3, Product=2, SerialNumber=1 [ 147.206448] usb usb3: Product: UHCI Host Controller [ 147.206450] usb usb3: Manufacturer: Linux 2.6.19-rc6-mm1 uhci_hcd [ 147.206451] usb usb3: SerialNumber: 0000:00:1d.3 [ 147.206477] usb usb3: configuration #1 chosen from 1 choice [ 147.206489] hub 3-0:1.0: USB hub found [ 147.206492] hub 3-0:1.0: 2 ports detected [ 147.421598] uhci_hcd 0000:00:1d.0: UHCI Host Controller [ 147.427070] uhci_hcd 0000:00:1d.0: new USB bus registered, assigned bus number 4 [ 147.434751] uhci_hcd 0000:00:1d.0: irq 20, io base 0x0000e480 [ 147.440796] usb usb4: new device found, idVendor=0000, idProduct=0000 [ 147.448538] usb usb4: new device strings: Mfr=3, Product=2, SerialNumber=1 [ 147.455593] usb usb4: Product: UHCI Host Controller [ 147.460591] usb usb4: Manufacturer: Linux 2.6.19-rc6-mm1 uhci_hcd [ 147.469255] usb usb4: SerialNumber: 0000:00:1d.0 [ 147.474562] usb usb4: configuration #1 chosen from 1 choice [ 147.480258] hub 4-0:1.0: USB hub found [ 147.484115] hub 4-0:1.0: 2 ports detected [ 147.517639] ACPI: PCI Interrupt 0000:00:1d.7[A] -> GSI 20 (level, low) -> IRQ 20 [ 147.525681] ehci_hcd 0000:00:1d.7: EHCI Host Controller [ 147.531082] ehci_hcd 0000:00:1d.7: new USB bus registered, assigned bus number 5 [ 147.538724] ehci_hcd 0000:00:1d.7: debug port 1 [ 147.543386] ehci_hcd 0000:00:1d.7: irq 20, io mem 0xfebfbc00 [ 147.553056] ehci_hcd 0000:00:1d.7: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004 [ 147.560798] usb usb5: new device found, idVendor=0000, idProduct=0000 [ 147.567356] usb usb5: new device strings: Mfr=3, Product=2, SerialNumber=1 [ 147.574394] usb usb5: Product: EHCI Host Controller [ 147.579382] usb usb5: Manufacturer: Linux 2.6.19-rc6-mm1 ehci_hcd [ 147.585609] usb usb5: SerialNumber: 0000:00:1d.7 [ 147.590675] ACPI: PCI Interrupt 0000:00:1b.0[A] -> GSI 19 (level, low) -> IRQ 19 [ 147.598091] usb usb5: configuration #1 chosen from 1 choice [ 147.598111] hub 5-0:1.0: USB hub found [ 147.598115] hub 5-0:1.0: 8 ports detected [ 147.664579] hda_codec: Unknown model for ALC882, trying auto-probe from BIOS... done. Setting parameters of disc: (none). Activating swap:swapon on /dev/sdc2 [ 148.501685] Adding 1959920k swap on /dev/sdc2. Priority:-1 extents:1 across:1959920k . Will now check root file system:fsck 1.40-WIP (14-Nov-2006) [/sbin/fsck.reiser4 (1) -- /] fsck.reiser4 -a /dev/sdc1 fsck.reiser4 /dev/sdc1 . Setting the system clock again.. [ 148.846087] usb 5-7: new high speed USB device using ehci_hcd and address 6 [ 148.971198] usb 5-7: new device found, idVendor=05e3, idProduct=0606 [ 148.977871] usb 5-7: new device strings: Mfr=0, Product=1, SerialNumber=0 [ 148.985141] usb 5-7: Product: USB2.0 Hub [ 148.989440] usb 5-7: configuration #1 chosen from 1 choice [ 148.995552] hub 5-7:1.0: USB hub found [ 148.999907] hub 5-7:1.0: 4 ports detected [ 149.179768] usb 4-1: new low speed USB device using uhci_hcd and address 2 [ 149.359046] usb 4-1: new device found, idVendor=045e, idProduct=001e [ 149.365905] usb 4-1: new device strings: Mfr=1, Product=2, SerialNumber=0 [ 149.373212] usb 4-1: Product: Microsoft IntelliMouse® Explorer [ 149.379456] usb 4-1: Manufacturer: Microsoft [ 149.384122] usb 4-1: configuration #1 chosen from 1 choice System Clock set. Local time: Sun Nov 26 22:56:23 MST 2006. Cleaning up ifupdown.... Loading kernel module nvidia. [ 149.527299] usb 4-2: new low speed USB device using uhci_hcd and address 3 [ 149.664808] usbcore: registered new interface driver hiddev [ 149.691745] usb 4-2: new device found, idVendor=0d3d, idProduct=0001 [ 149.698254] usb 4-2: new device strings: Mfr=0, Product=2, SerialNumber=0 [ 149.705179] usb 4-2: Product: USBPS2 [ 149.708899] usb 4-2: configuration #1 chosen from 1 choice [ 149.870517] usb 2-1: new full speed USB device using uhci_hcd and address 3 [ 149.990442] usb 2-1: device descriptor read/64, error -71 [ 150.209320] usb 2-1: device descriptor read/64, error -71 [ 150.257283] nvidia: module license 'NVIDIA' taints kernel. [ 150.416927] usb 2-1: new full speed USB device using uhci_hcd and address 4 [ 150.515873] NVRM: The NVIDIA probe routine was not called for 1 device(s). [ 150.515890] ACPI: PCI Interrupt 0000:04:00.0[A] -> GSI 16 (level, low) -> IRQ 16 [ 150.530441] NVRM: This can occur when a driver such as rivafb, nvidiafb or [ 150.530442] NVRM: rivatv was loaded and obtained ownership of the NVIDIA [ 150.530443] NVRM: device(s). [ 150.536819] usb 2-1: device descriptor read/64, error -71 [ 150.552801] NVRM: Try unloading the rivafb, nvidiafb or rivatv kernel module [ 150.552802] NVRM: (and/or reconfigure your kernel without rivafb/nvidiafb [ 150.552803] NVRM: support), then try loading the NVIDIA kernel module again. [ 150.574122] NVRM: loading NVIDIA Linux x86_64 Kernel Module 1.0-9629 Wed Nov 1 19:27:33 PST 2006 Loading kernel module loop. FATAL: Module loop not found. Loading kernel module i2c-i801. Loading kernel module i2c-isa. Loading kernel module eeprom. Loading kernel module w83627ehf. Loading kernel module usb-storage. [ 150.655320] Initializing USB Mass Storage driver... [ 150.752226] usb 2-1: device descriptor read/64, error -71 [ 150.961220] usb 2-1: new full speed USB device using uhci_hcd and address 5 [ 151.376260] usb 2-1: device not accepting address 5, error -71 [ 151.484845] usb 2-1: new full speed USB device using uhci_hcd and address 6 [ 151.899912] usb 2-1: device not accepting address 6, error -71 [ 152.112034] usb 2-2: new full speed USB device using uhci_hcd and address 7 [ 152.419953] usb 5-7.3: new high speed USB device using ehci_hcd and address 7 [ 152.511368] usb 5-7.3: new device found, idVendor=0bda, idProduct=8187 [ 152.518346] usb 5-7.3: new device strings: Mfr=1, Product=2, SerialNumber=3 [ 152.525398] usb 5-7.3: Product: RTL8187_Wireless [ 152.530085] usb 5-7.3: Manufacturer: Manufacturer_Realtek_RTL8187_ [ 152.531240] input: Microsoft Microsoft IntelliMouse® Explorer as /class/input/input3 [ 152.531376] input: USB HID v1.00 Mouse [Microsoft Microsoft IntelliMouse® Explorer] on usb-0000:00:1d.0-1 [ 152.553989] usb 5-7.3: SerialNumber: 0015AF05C9DE [ 152.558883] usb 5-7.3: configuration #1 chosen from 1 choice [ 152.564748] input: USBPS2 as /class/input/input4 [ 152.569559] input: USB HID v1.00 Keyboard [USBPS2] on usb-0000:00:1d.0-2 [ 152.598228] input: USBPS2 as /class/input/input5 [ 152.603008] input: USB HID v1.00 Mouse [USBPS2] on usb-0000:00:1d.0-2 [ 152.609682] usbcore: registered new interface driver usbhid [ 152.612079] usbcore: registered new interface driver usb-storage [ 152.612081] USB Mass Storage support registered. [ 152.626231] drivers/usb/input/hid-core.c: v2.6:USB HID core driver Loading kernel module snd-rtctimer. Loading kernel module uhci-hcd. Loading kernel module acpi-cpufreq. FATAL: Error inserting acpi_cpuf[ 152.674231] usbcore: registered new interface driver cdc_acm req (/lib/module[ 152.680227] drivers/usb/class/cdc-acm.c: v0.25:USB Abstract Control Model driver for USB modems and ISDN adapters s/2.6.19-rc6-mm1/kernel/arch/x86_64/kernel/cpufreq/acpi-cpufreq.ko): No such device Loading kernel module cdc-acm. Loading device-mapper support. Will now check all file systems. fsck 1.40-WIP (14-Nov-2006) Checking all file systems. Done checking file systems. A log is being saved in /var/log/fsck/checkfs if that location is writable. Setting kernel variables...done. Will now mount local filesystems:[ 152.853692] ReiserFS: sde1: found reiserfs format "3.6" with standard journal [ 152.860994] ReiserFS: sde1: using ordered data mode [ 152.875751] ReiserFS: sde1: journal params: device sde1, size 8192, journal first block 18, max trans len 1024, max batch 900, max commit age 30, max trans age 30 [ 152.890838] ReiserFS: sde1: checking transaction log (sde1) [ 152.968048] ReiserFS: sde1: Using r5 hash to sort names [ 153.035606] reiser4: sda1: found disk format 4.0.0. . Will now activate swapfile swap:done. Cleaning /tmp...done. Cleaning /var/run...done. Cleaning /var/lock...done. Setting up networking.... Configuring network interfaces...done. Starting portmap daemon.... [ 154.803119] sky2 eth0: enabling interface Setting sensors limits: done. Setting console screen modes and fonts. Setting up ALSA...done. Initializing random number generator...done. Recovering nvi editor sessions...none found. Setting up X server socket directory /tmp/.X11-unix.... Setting up ICE socket directory /tmp/.ICE-unix.... Recovering schroot sessions... done. INIT: Entering runlevel: 2 Starting system log daemon.... Starting kernel log daemon.... Loading ACPI modules: Starting Advanced Configuration and Power Interface daemon: acpid. Starting Common Unix Printing System: cupsd[ 157.299194] usb 2-2: new device found, idVendor=03f0, idProduct=0401 [ 157.305711] usb 2-2: new device strings: Mfr=1, Product=2, SerialNumber=3 [ 157.312652] usb 2-2: Product: HP ScanJet 5200C [ 157.317694] sky2 eth0: Link is up at 1000 Mbps, full duplex, flow control both [ 157.325090] usb 2-2: Manufacturer: Hewlett-Packard [ 157.329976] usb 2-2: SerialNumber: SG91U161Z2HT [ 157.334680] usb 2-2: configuration #1 chosen from 1 choice . Starting system message bus: dbus. Starting Hardware abstraction layer: hald. Starting DirMngr: dirmngr. Starting mouse interface server: gpm. Starting internet superserver: inetd. Starting Postfix Mail Transport Agent: postfix. Starting Samba daemons: nmbd smbd. Starting sensor daemon: sensord. Starting OpenBSD Secure Shell server: sshd. Setting up X font server socket directory /tmp/.font-unix...done. Starting X font server: xfs. Starting NFS common utilities: statd. Starting NTP server: ntpd. Starting deferred execution scheduler: atd. Starting periodic command scheduler: crond. Starting K Display Manager: kdm. Running local boot scripts (/etc/rc.local). Debian GNU/Linux 4.0 luna ttyS0 luna login: INIT:Stopping K Display Manager: kdm. Stopping deferred execution scheduler: atd. Stopping periodic command scheduler: crond. Stopping Samba daemons: nmbd smbd. Stopping Advanced Configuration and Power Interface daemon: acpid. Stopping Common Unix Printing System: cupsd. Stopping Hardware abstraction layer: hald. Stopping system message bus: dbus. Stopping DirMngr: dirmngr. Stopping mouse interface server: gpm. Stopping internet superserver: inetd. Stopping Postfix Mail Transport Agent: postfix. Stopping sensor daemon: sensord. Stopping OpenBSD Secure Shell server: sshd. Stopping X font server: xfs. Stopping NTP server: ntpd. Saving the system clock.. Hardware Clock updated to Mon Nov 27 01:30:01 MST 2006. Shutting down ALSA...done. Stopping NFS common utilities: statd. Stopping kernel log daemon.... Stopping system log daemon.... Saving random seed...done. Asking non-system processes to terminate...done. Unmounting remote and non-toplevel virtual filesystems...done. Stopping portmap daemon.... Deconfiguring network interfaces...[ 9363.903564] sky2 eth0: disabling interface done. Cleaning up ifupdown.... Asking all remaining processes to terminate...done. Killing all remaining processes...done. Will now unmount temporary filesystems:/dev umounted . Will now deactivate swap:swapoff on /dev/sdc2 . Will now unmount local filesystems:/backup umounted /home umounted /tmp umounted /dev/sde1 umounted /dev/sda1 umounted /dev/hde1 umounted . Mounting root filesystem read-only...done. Will now halt. [ 9371.896444] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 [ 9371.903036] ata2.00: (irq_stat 0x40000001) [ 9371.907228] ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/00 tag 0 data 0 in [ 9371.907229] res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error) [ 9371.931688] ata2.00: configured for UDMA/133 [ 9371.936073] ata2: EH complete [ 9371.939137] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 [ 9371.945702] ata2.00: (irq_stat 0x40000001) [ 9371.949899] ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/00 tag 0 data 0 in [ 9371.949900] res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error) [ 9371.974319] ata2.00: configured for UDMA/133 [ 9371.978701] ata2: EH complete [ 9371.981763] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 [ 9371.988346] ata2.00: (irq_stat 0x40000001) [ 9371.992543] ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/00 tag 0 data 0 in [ 9371.992544] res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error) [ 9372.016961] ata2.00: configured for UDMA/133 [ 9372.021345] ata2: EH complete [ 9372.024417] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 [ 9372.030990] ata2.00: (irq_stat 0x40000001) [ 9372.035190] ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/00 tag 0 data 0 in [ 9372.035191] res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error) [ 9372.059604] ata2.00: configured for UDMA/133 [ 9372.063981] ata2: EH complete [ 9372.067053] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 [ 9372.073634] ata2.00: (irq_stat 0x40000001) [ 9372.077834] ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/00 tag 0 data 0 in [ 9372.077835] res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error) [ 9372.102259] ata2.00: configured for UDMA/133 [ 9372.106633] ata2: EH complete [ 9372.109702] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 [ 9372.116280] ata2.00: (irq_stat 0x40000001) [ 9372.120471] ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/00 tag 0 data 0 in [ 9372.120472] res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error) [ 9372.144866] ata2.00: configured for UDMA/133 [ 9372.149237] ata2: EH complete [ 9372.152310] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 [ 9372.158882] ata2.00: (irq_stat 0x40000001) [ 9372.163079] ata2.00: cmd 94/00:00:00:00:00/00:00:00:00:00/00 tag 0 data 0 in [ 9372.163080] res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error) [ 9372.187505] ata2.00: configured for UDMA/133 [ 9372.191891] ata2: EH complete [ 9372.194954] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 [ 9372.201528] ata2.00: (irq_stat 0x40000001) [ 9372.205725] ata2.00: cmd 94/00:00:00:00:00/00:00:00:00:00/00 tag 0 data 0 in [ 9372.205726] res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error) [ 9372.230150] ata2.00: configured for UDMA/133 [ 9372.234525] ata2: EH complete [ 9372.237590] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 [ 9372.244171] ata2.00: (irq_stat 0x40000001) [ 9372.248370] ata2.00: cmd 94/00:00:00:00:00/00:00:00:00:00/00 tag 0 data 0 in [ 9372.248371] res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error) [ 9372.272791] ata2.00: configured for UDMA/133 [ 9372.277161] ata2: EH complete [ 9372.280236] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 [ 9372.286818] ata2.00: (irq_stat 0x40000001) [ 9372.291015] ata2.00: cmd 94/00:00:00:00:00/00:00:00:00:00/00 tag 0 data 0 in [ 9372.291016] res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error) [ 9372.315408] ata2.00: configured for UDMA/133 [ 9372.319772] ata2: EH complete [ 9372.322838] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 [ 9372.329410] ata2.00: (irq_stat 0x40000001) [ 9372.333607] ata2.00: cmd 94/00:00:00:00:00/00:00:00:00:00/00 tag 0 data 0 in [ 9372.333608] res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error) [ 9372.358023] ata2.00: configured for UDMA/133 [ 9372.362390] ata2: EH complete [ 9372.365463] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 [ 9372.372036] ata2.00: (irq_stat 0x40000001) [ 9372.376236] ata2.00: cmd 94/00:00:00:00:00/00:00:00:00:00/00 tag 0 data 0 in [ 9372.376237] res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error) [ 9372.400648] ata2.00: configured for UDMA/133 [ 9372.405018] ata2: EH complete [ 9372.408077] SCSI device sdd: 640 512-byte hdwr sectors (0 MB) [ 9372.410277] Synchronizing SCSI cache for disk sde: [ 9372.418928] sdd: Write Protect is off [ 9372.422679] SCSI device sdd: write cache: disabled, read cache: enabled, doesn't support DPO or FUA [ 9372.431950] SCSI device sdd: 640 512-byte hdwr sectors (0 MB) [ 9372.437839] sdd: Write Protect is off [ 9372.441609] SCSI device sdd: write cache: disabled, read cache: enabled, doesn't support DPO or FUA [ 9372.450324] Synchronizing SCSI cache for disk sdc: [ 9372.450480] Synchronizing SCSI cache for disk sdb: [ 9372.450732] Synchronizing SCSI cache for disk sda: [ 9372.942537] Shutdown: hdg [ 9372.945441] Shutdown: hde [ 9372.948690] Power down. [ 9372.951278] acpi_power_off called ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: 2.6.18 - AHCI detection pauses excessively 2006-11-27 8:58 ` Berck E. Nash @ 2006-11-29 8:55 ` Tejun Heo 2006-11-29 18:53 ` Berck E. Nash 0 siblings, 1 reply; 12+ messages in thread From: Tejun Heo @ 2006-11-29 8:55 UTC (permalink / raw) To: Berck E. Nash; +Cc: linux-kernel@vger.kernel.org, linux-ide@vger.kernel.org [-- Attachment #1: Type: text/plain, Size: 1755 bytes --] Berck E. Nash wrote: > Tejun Heo wrote: > >> Yeah, I did and forgot about this thread too. Sorry. This is on the >> top of my to-do list now. I'm attaching the patch. TIA. > > That didn't fix the problem, but did change the messages. I've attached > the entire log, including the weird errors on power-off from the same > device that gives problems on boot, which I suspect are related. Hmm... this is difficult. The problem is that everything looks normal until command is issued. My primary suspect still is ahci powering down phy during initialization. Can you please test the attached patch again? [--snip--] > Mounting root filesystem read-only...done. > Will now halt. > [ 9371.896444] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 > [ 9371.903036] ata2.00: (irq_stat 0x40000001) > [ 9371.907228] ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/00 tag 0 data 0 in > [ 9371.907229] res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error) > [ 9371.931688] ata2.00: configured for UDMA/133 > [ 9371.936073] ata2: EH complete Weird, the drive is failing STANDBY IMMEDIATE. [--snip--] > [ 9372.152310] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 > [ 9372.158882] ata2.00: (irq_stat 0x40000001) > [ 9372.163079] ata2.00: cmd 94/00:00:00:00:00/00:00:00:00:00/00 tag 0 data 0 in > [ 9372.163080] res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error) > [ 9372.187505] ata2.00: configured for UDMA/133 Then, a series of obsolete STANDBY failures. Who's issuing these commands? It's not libata, libata uses STANDBY (0xe2). Is it some kind of gentoo thing? Anyways, doesn't really matter although it's surprising that the drive fails STANDBY IMMEDIATE. Thanks. -- tejun [-- Attachment #2: patch --] [-- Type: text/plain, Size: 1543 bytes --] diff --git a/drivers/ata/ahci.c b/drivers/ata/ahci.c index 8f75c60..6100cbc 100644 --- a/drivers/ata/ahci.c +++ b/drivers/ata/ahci.c @@ -612,9 +612,6 @@ static void ahci_power_down(void __iomem static void ahci_init_port(void __iomem *port_mmio, u32 cap, dma_addr_t cmd_slot_dma, dma_addr_t rx_fis_dma) { - /* power up */ - ahci_power_up(port_mmio, cap); - /* enable FIS reception */ ahci_start_fis_rx(port_mmio, cap, cmd_slot_dma, rx_fis_dma); @@ -640,9 +637,6 @@ static int ahci_deinit_port(void __iomem return rc; } - /* put device into slumber mode */ - ahci_power_down(port_mmio, cap); - return 0; } @@ -1321,7 +1315,9 @@ static int ahci_port_suspend(struct ata_ int rc; rc = ahci_deinit_port(port_mmio, hpriv->cap, &emsg); - if (rc) { + if (rc == 0) + ahci_power_down(port_mmio, hpriv->cap); + else { ata_port_printk(ap, KERN_ERR, "%s (%d)\n", emsg, rc); ahci_init_port(port_mmio, hpriv->cap, pp->cmd_slot_dma, pp->rx_fis_dma); @@ -1337,6 +1333,7 @@ static int ahci_port_resume(struct ata_p void __iomem *mmio = ap->host->mmio_base; void __iomem *port_mmio = ahci_port_base(mmio, ap->port_no); + ahci_power_up(port_mmio, hpriv->cap); ahci_init_port(port_mmio, hpriv->cap, pp->cmd_slot_dma, pp->rx_fis_dma); return 0; @@ -1443,6 +1440,9 @@ static int ahci_port_start(struct ata_po ap->private_data = pp; + /* power up port */ + ahci_power_up(port_mmio, hpriv->cap); + /* initialize port */ ahci_init_port(port_mmio, hpriv->cap, pp->cmd_slot_dma, pp->rx_fis_dma); ^ permalink raw reply related [flat|nested] 12+ messages in thread
* Re: 2.6.18 - AHCI detection pauses excessively 2006-11-29 8:55 ` Tejun Heo @ 2006-11-29 18:53 ` Berck E. Nash 2006-11-29 19:27 ` Mark Lord 2006-12-01 7:07 ` Tejun Heo 0 siblings, 2 replies; 12+ messages in thread From: Berck E. Nash @ 2006-11-29 18:53 UTC (permalink / raw) To: Tejun Heo; +Cc: linux-kernel@vger.kernel.org, linux-ide@vger.kernel.org [-- Attachment #1: Type: text/plain, Size: 640 bytes --] Tejun Heo wrote: > Hmm... this is difficult. The problem is that everything looks normal > until command is issued. My primary suspect still is ahci powering down > phy during initialization. Can you please test the attached patch again? No significant difference that I can tell. I've attached the whole log from boot to power-down. That's with both this patch and the previous patch. If you want just one, I can do that as well... > Then, a series of obsolete STANDBY failures. Who's issuing these > commands? It's not libata, libata uses STANDBY (0xe2). Is it some kind > of gentoo thing? Nope, Debian/Unstable. Berck [-- Attachment #2: consolelog --] [-- Type: text/plain, Size: 42416 bytes --] [ 0.000000] Linux version 2.6.19-rc6-mm1 (root@luna) (gcc version 4.1.2 20061115 (prerelease) (Debian 4.1.1-20)) #4 SMP PREEMPT Wed Nov 29 09:40:25 MST 2006 [ 0.000000] Command line: root=/dev/sdc1 ro console=tty0 console=ttyS0,115200n8 BOOT_IMAGE=vmlinuz [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: 0000000000000000 - 000000000009fc00 (usable) [ 0.000000] BIOS-e820: 000000000009fc00 - 00000000000a0000 (reserved) [ 0.000000] BIOS-e820: 00000000000e4000 - 0000000000100000 (reserved) [ 0.000000] BIOS-e820: 0000000000100000 - 000000003ff80000 (usable) [ 0.000000] BIOS-e820: 000000003ff80000 - 000000003ff8e000 (ACPI data) [ 0.000000] BIOS-e820: 000000003ff8e000 - 000000003ffe0000 (ACPI NVS) [ 0.000000] BIOS-e820: 000000003ffe0000 - 0000000040000000 (reserved) [ 0.000000] BIOS-e820: 00000000ffb00000 - 0000000100000000 (reserved) [ 0.000000] end_pfn_map = 1048576 [ 0.000000] DMI 2.4 present. [ 0.000000] Zone PFN ranges: [ 0.000000] DMA 0 -> 4096 [ 0.000000] DMA32 4096 -> 1048576 [ 0.000000] Normal 1048576 -> 1048576 [ 0.000000] early_node_map[2] active PFN ranges [ 0.000000] 0: 0 -> 159 [ 0.000000] 0: 256 -> 262016 [ 0.000000] ACPI: PM-Timer IO Port: 0x808 [ 0.000000] ACPI: LAPIC (acpi_id[0x01] lapic_id[0x00] enabled) [ 0.000000] Processor #0 (Bootup-CPU) [ 0.000000] ACPI: LAPIC (acpi_id[0x02] lapic_id[0x01] enabled) [ 0.000000] Processor #1 [ 0.000000] ACPI: LAPIC (acpi_id[0x03] lapic_id[0x82] disabled) [ 0.000000] ACPI: LAPIC (acpi_id[0x04] lapic_id[0x83] disabled) [ 0.000000] ACPI: IOAPIC (id[0x02] address[0xfec00000] gsi_base[0]) [ 0.000000] IOAPIC[0]: apic_id 2, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] Setting APIC routing to flat [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] Nosave address range: 000000000009f000 - 00000000000a0000 [ 0.000000] Nosave address range: 00000000000a0000 - 00000000000e4000 [ 0.000000] Nosave address range: 00000000000e4000 - 0000000000100000 [ 0.000000] Allocating PCI resources starting at 50000000 (gap: 40000000:bfb00000) [ 0.000000] PERCPU: Allocating 32512 bytes of per cpu data [ 0.000000] Built 1 zonelists. Total pages: 257375 [ 0.000000] Kernel command line: root=/dev/sdc1 ro console=tty0 console=ttyS0,115200n8 BOOT_IMAGE=vmlinuz [ 0.000000] Initializing CPU#0 [ 0.000000] PID hash table entries: 4096 (order: 12, 32768 bytes) [ 57.051783] Console: colour VGA+ 80x25 [ 57.314953] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes) [ 57.322333] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes) [ 57.329293] Checking aperture... [ 57.340073] Memory: 1027700k/1048064k available (2281k kernel code, 19860k reserved, 999k data, 196k init) [ 57.409313] Calibrating delay using timer specific routine.. 5800.15 BogoMIPS (lpj=2900076) [ 57.417779] Mount-cache hash table entries: 256 [ 57.422423] CPU: L1 I cache: 32K, L1 D cache: 32K [ 57.427211] CPU: L2 cache: 2048K [ 57.430763] using mwait in idle threads. [ 57.434721] CPU: Physical Processor ID: 0 [ 57.438764] CPU: Processor Core ID: 0 [ 57.442465] CPU0: Thermal monitoring enabled (TM2) [ 57.447302] Freeing SMP alternatives: 24k freed [ 57.451874] ACPI: Core revision 20060707 [ 57.480782] Using local APIC timer interrupts. [ 57.519735] result 25877174 [ 57.522568] Detected 25.877 MHz APIC timer. [ 57.527253] Booting processor 1/2 APIC 0x1 [ 57.541734] Initializing CPU#1 [ 57.602132] Calibrating delay using timer specific routine.. 5796.48 BogoMIPS (lpj=2898240) [ 57.602137] CPU: L1 I cache: 32K, L1 D cache: 32K [ 57.602138] CPU: L2 cache: 2048K [ 57.602139] CPU: Physical Processor ID: 0 [ 57.602140] CPU: Processor Core ID: 1 [ 57.602144] CPU1: Thermal monitoring enabled (TM2) [ 57.602335] Intel(R) Core(TM)2 CPU 6300 @ 1.86GHz stepping 06 [ 57.603137] Brought up 2 CPUs [ 57.645024] testing NMI watchdog ... OK. [ 57.659029] time.c: Using 14.318180 MHz WALL HPET GTOD HPET/TSC timer. [ 57.665585] time.c: Detected 2898.246 MHz processor. [ 57.783220] migration_cost=29 [ 57.786529] NET: Registered protocol family 16 [ 57.791012] wait_for_probes: waiting for 0 threads [ 57.795876] wait_for_probes: waiting for 0 threads [ 57.800706] ACPI: bus type pci registered [ 57.804751] PCI: BIOS Bug: MCFG area at f0000000 is not E820-reserved [ 57.811226] PCI: Not using MMCONFIG. [ 57.814834] PCI: Using configuration type 1 [ 57.819050] wait_for_probes: waiting for 0 threads [ 57.831652] ACPI: Interpreter enabled [ 57.835347] ACPI: Using IOAPIC for interrupt routing [ 57.841073] ACPI: PCI Root Bridge [PCI0] (0000:00) [ 57.846380] PCI quirk: region 0800-087f claimed by ICH6 ACPI/GPIO/TCO [ 57.852852] PCI quirk: region 0480-04bf claimed by ICH6 GPIO [ 57.859013] PCI: Transparent bridge - 0000:00:1e.0 [ 57.870873] ACPI: PCI Interrupt Link [LNKA] (IRQs 3 4 5 6 7 10 *11 12 14 15) [ 57.878847] ACPI: PCI Interrupt Link [LNKB] (IRQs 3 4 5 6 *7 10 11 12 14 15) [ 57.886660] ACPI: PCI Interrupt Link [LNKC] (IRQs *3 4 5 6 7 10 11 12 14 15) [ 57.894433] ACPI: PCI Interrupt Link [LNKD] (IRQs 3 4 5 6 7 *10 11 12 14 15) [ 57.902208] ACPI: PCI Interrupt Link [LNKE] (IRQs 3 4 *5 6 7 10 11 12 14 15) [ 57.909984] ACPI: PCI Interrupt Link [LNKF] (IRQs 3 4 5 6 7 10 *11 12 14 15) [ 57.917758] ACPI: PCI Interrupt Link [LNKG] (IRQs 3 4 *5 6 7 10 11 12 14 15) [ 57.925533] ACPI: PCI Interrupt Link [LNKH] (IRQs 3 4 5 6 7 *10 11 12 14 15) [ 57.933201] Linux Plug and Play Support v0.97 (c) Adam Belay [ 57.938896] pnp: PnP ACPI init [ 57.944754] pnp: PnP ACPI: found 15 devices [ 57.949002] intel_rng: FWH not detected [ 57.952961] SCSI subsystem initialized [ 57.956786] PCI: Using ACPI for IRQ routing [ 57.961004] PCI: If a device doesn't work, try "pci=routeirq". If it helps, post a report [ 57.969356] wait_for_probes: waiting for 0 threads [ 57.974185] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 57.979267] hpet0: 3 64-bit timers, 14318180 Hz [ 57.984835] PCI-GART: No AMD northbridge found. [ 57.989915] pnp: 00:07: ioport range 0x290-0x297 has been reserved [ 57.996305] PCI: Bridge: 0000:00:01.0 [ 58.000003] IO window: disabled. [ 58.003442] MEM window: faa00000-feafffff [ 58.007658] PREFETCH window: cff00000-efefffff [ 58.012307] PCI: Bridge: 0000:00:1c.0 [ 58.016005] IO window: disabled. [ 58.019441] MEM window: disabled. [ 58.022966] PREFETCH window: cfe00000-cfefffff [ 58.027618] PCI: Bridge: 0000:00:1c.3 [ 58.031313] IO window: c000-cfff [ 58.034752] MEM window: fa900000-fa9fffff [ 58.038969] PREFETCH window: disabled. [ 58.042926] PCI: Bridge: 0000:00:1e.0 [ 58.046625] IO window: b000-bfff [ 58.050061] MEM window: fa700000-fa8fffff [ 58.054278] PREFETCH window: 50000000-500fffff [ 58.058935] ACPI: PCI Interrupt 0000:00:01.0[A] -> GSI 16 (level, low) -> IRQ 16 [ 58.066426] ACPI: PCI Interrupt 0000:00:1c.0[A] -> GSI 16 (level, low) -> IRQ 16 [ 58.073918] ACPI: PCI Interrupt 0000:00:1c.3[D] -> GSI 19 (level, low) -> IRQ 19 [ 58.081418] NET: Registered protocol family 2 [ 58.097867] IP route cache hash table entries: 32768 (order: 6, 262144 bytes) [ 58.105121] TCP established hash table entries: 131072 (order: 9, 2097152 bytes) [ 58.113201] TCP bind hash table entries: 65536 (order: 8, 1048576 bytes) [ 58.120434] TCP: Hash tables configured (established 131072 bind 65536) [ 58.127074] TCP reno registered [ 58.133898] wait_for_probes: waiting for 0 threads [ 58.139183] audit: initializing netlink socket (disabled) [ 58.144620] audit(1164794340.588:1): initialized [ 58.154651] Loading Reiser4. See www.namesys.com for a description of Reiser4. [ 58.161964] io scheduler noop registered [ 58.165971] io scheduler anticipatory registered (default) [ 58.171764] assign_interrupt_mode Found MSI capability [ 58.177008] assign_interrupt_mode Found MSI capability [ 58.182267] assign_interrupt_mode Found MSI capability [ 58.187624] input: Power Button (FF) as /class/input/input0 [ 58.193229] ACPI: Power Button (FF) [PWRF] [ 58.197399] input: Power Button (CM) as /class/input/input1 [ 58.203002] ACPI: Power Button (CM) [PWRB] [ 58.207441] ACPI: Processor [CPU1] (supports 8 throttling states) [ 58.213880] ACPI: Processor [CPU2] (supports 8 throttling states) [ 58.220091] ACPI: Getting cpuindex for acpiid 0x3 [ 58.224832] ACPI: Getting cpuindex for acpiid 0x4 [ 58.230921] Real Time Clock Driver v1.12ac [ 58.235124] Linux agpgart interface v0.101 (c) Dave Jones [ 58.240558] Serial: 8250/16550 driver $Revision: 1.90 $ 4 ports, IRQ sharing disabled [ 58.248508] serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A [ 58.254844] 00:0c: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A [ 58.260556] Uniform Multi-Platform E-IDE driver Revision: 7.00alpha2 [ 58.266942] ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx [ 58.274999] ICH7: IDE controller at PCI slot 0000:00:1f.1 [ 58.280435] ACPI: PCI Interrupt 0000:00:1f.1[A] -> GSI 22 (level, low) -> IRQ 22 [ 58.287921] ICH7: chipset revision 1 [ 58.291530] ICH7: not 100% native mode: will probe irqs later [ 58.297312] ide0: BM-DMA at 0xffa0-0xffa7, BIOS settings: hda:DMA, hdb:DMA [ 58.304673] ide1: BM-DMA at 0xffa8-0xffaf, BIOS settings: hdc:pio, hdd:pio [ 58.983800] hda: LITE-ON LTR-48246S, ATAPI CD/DVD-ROM drive [ 59.703341] hdb: _NEC DVD_RW ND-3520AW, ATAPI CD/DVD-ROM drive [ 59.763054] ide0 at 0x1f0-0x1f7,0x3f6 on irq 14 [ 60.286513] SiI680: IDE controller at PCI slot 0000:01:00.0 [ 60.292127] ACPI: PCI Interrupt 0000:01:00.0[A] -> GSI 21 (level, low) -> IRQ 21 [ 60.299607] SiI680: chipset revision 2 [ 60.303401] SiI680: BASE CLOCK == 133 [ 60.307144] SiI680: 100% native mode on irq 21 [ 60.311618] ide2: MMIO-DMA , BIOS settings: hde:pio, hdf:pio [ 60.317754] ide3: MMIO-DMA , BIOS settings: hdg:pio, hdh:pio [ 60.589630] hde: SAMSUNG WN316025A (1.6 GB), ATA DISK drive [ 61.206447] ide2 at 0xffffc20000006c80-0xffffc20000006c87,0xffffc20000006c8a on irq 21 [ 61.478377] hdg: MAXTOR 6L040J2, ATA DISK drive [ 62.094234] ide3 at 0xffffc20000006cc0-0xffffc20000006cc7,0xffffc20000006cca on irq 21 [ 62.102331] hde: max request size: 64KiB [ 62.106288] hde: 3145968 sectors (1610 MB) w/109KiB Cache, CHS=3121/16/63, DMA [ 62.113752] hde: hde1 [ 62.130460] hdg: max request size: 64KiB [ 62.135458] hdg: 78198750 sectors (40037 MB) w/1819KiB Cache, CHS=65535/16/63, UDMA(133) [ 62.143920] hdg: cache flushes supported [ 62.147886] hdg: hdg1 [ 62.166751] hda: ATAPI 48X CD-ROM CD-R/RW drive, 2048kB Cache, UDMA(33) [ 62.173727] Uniform CD-ROM driver Revision: 3.20 [ 62.218007] hdb: ATAPI 48X DVD-ROM DVD-R CD-R/RW drive, 2048kB Cache, UDMA(33) [ 62.239427] ACPI: PCI Interrupt 0000:01:01.0[A] -> GSI 22 (level, low) -> IRQ 22 [ 62.248581] ACPI: PCI Interrupt 0000:00:1f.2[B] -> GSI 23 (level, low) -> IRQ 23 [ 62.256246] PNP: PS/2 Controller [PNP0303:PS2K] at 0x60,0x64 irq 1 [ 62.262462] PNP: PS/2 controller doesn't have AUX irq; using default 12 [ 62.271704] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 62.276717] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 62.281869] mice: PS/2 mouse device common for all mice [ 62.287138] EDAC MC: Ver: 2.0.1 Nov 25 2006 [ 62.291460] TCP cubic registered [ 62.294723] Initializing XFRM netlink socket [ 62.299034] NET: Registered protocol family 1 [ 62.303431] NET: Registered protocol family 17 [ 62.307920] NET: Registered protocol family 15 [ 62.312402] wait_for_probes: waiting for 3 threads [ 62.320615] input: AT Translated Set 2 keyboard as /class/input/input2 [ 62.456583] scsi0 : Adaptec AIC7XXX EISA/VLB/PCI SCSI HBA DRIVER, Rev 7.0 [ 62.456584] <Adaptec 2940 Ultra2 SCSI adapter> [ 62.456585] aic7890/91: Ultra2 Wide Channel A, SCSI Id=7, 32/253 SCBs [ 62.456586] [ 62.737004] scsi 0:0:1:0: Direct-Access IBM-PCCO ST39102LC !# B219 PQ: 0 ANSI: 2 [ 62.745138] scsi0:A:1:0: Tagged Queuing enabled. Depth 8 [ 62.750622] target0:0:1: Beginning Domain Validation [ 62.762123] target0:0:1: wide asynchronous [ 62.771039] target0:0:1: FAST-40 WIDE SCSI 80.0 MB/s ST (25 ns, offset 15) [ 62.782253] target0:0:1: Domain Validation skipping write tests [ 62.788289] target0:0:1: Ending Domain Validation [ 62.796097] scsi 0:0:2:0: Direct-Access SGI SEAGATE ST39102L 2702 PQ: 0 ANSI: 2 [ 62.804226] scsi0:A:2:0: Tagged Queuing enabled. Depth 8 [ 62.809710] target0:0:2: Beginning Domain Validation [ 62.820068] target0:0:2: wide asynchronous [ 62.828148] target0:0:2: FAST-40 WIDE SCSI 80.0 MB/s ST (25 ns, offset 15) [ 62.838546] target0:0:2: Domain Validation skipping write tests [ 62.844580] target0:0:2: Ending Domain Validation [ 63.256906] ahci 0000:00:1f.2: AHCI 0001.0100 32 slots 4 ports 3 Gbps 0xf impl SATA mode [ 63.265032] ahci 0000:00:1f.2: flags: 64bit ncq pm led clo pio slum part [ 63.271894] ata1: SATA max UDMA/133 cmd 0xFFFFC2000000E900 ctl 0x0 bmdma 0x0 irq 316 [ 63.279711] ata2: SATA max UDMA/133 cmd 0xFFFFC2000000E980 ctl 0x0 bmdma 0x0 irq 316 [ 63.287529] ata3: SATA max UDMA/133 cmd 0xFFFFC2000000EA00 ctl 0x0 bmdma 0x0 irq 316 [ 63.295348] ata4: SATA max UDMA/133 cmd 0xFFFFC2000000EA80 ctl 0x0 bmdma 0x0 irq 316 [ 63.303134] scsi1 : ahci [ 63.607369] SATA PHY: stable DET=3 [ 63.711788] SATA PHY: stable DET=3 [ 63.816363] SATA PHY: stable DET=3 [ 63.920860] SATA PHY: stable DET=3 [ 64.024318] SATA PHY: stable DET=3 [ 64.128893] SATA PHY: stable DET=3 [ 64.233299] SATA PHY: stable DET=3 [ 64.337874] SATA PHY: stable DET=3 [ 64.442358] SATA PHY: stable DET=3 [ 64.545829] SATA PHY: stable DET=3 [ 64.650405] SATA PHY: stable DET=3 [ 64.754810] SATA PHY: stable DET=3 [ 64.859385] SATA PHY: stable DET=3 [ 64.963830] SATA PHY: stable DET=3 [ 65.067327] SATA PHY: stable DET=3 [ 65.171915] SATA PHY: stable DET=3 [ 65.276320] SATA PHY: stable DET=3 [ 65.380895] SATA PHY: stable DET=3 [ 65.485327] SATA PHY: stable DET=3 [ 65.588851] SATA PHY: stable DET=3 [ 65.592287] SATA PHY: debounced [ 65.750171] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300) [ 65.763279] ata1.00: ATA-6, max UDMA/133, 72303840 sectors: LBA48 [ 65.769497] ata1.00: ata1: dev 0 multi count 16 [ 65.781925] ata1.00: configured for UDMA/133 [ 65.786233] scsi2 : ahci [ 65.926221] SCSI device sda: 17774160 512-byte hdwr sectors (9100 MB) [ 65.934661] sda: Write Protect is off [ 65.939927] SCSI device sda: write cache: enabled, read cache: enabled, supports DPO and FUA [ 65.949193] SCSI device sda: 17774160 512-byte hdwr sectors (9100 MB) [ 65.957643] sda: Write Protect is off [ 65.962922] SCSI device sda: write cache: enabled, read cache: enabled, supports DPO and FUA [ 65.971395] sda: sda1 sda2 [ 65.981209] sd 0:0:1:0: Attached scsi disk sda [ 65.985718] sd 0:0:1:0: Attached scsi generic sg0 type 0 [ 65.991862] SCSI device sdb: 17781520 512-byte hdwr sectors (9104 MB) [ 66.001710] sdb: Write Protect is off [ 66.009177] SCSI device sdb: write cache: enabled, read cache: enabled, supports DPO and FUA [ 66.018402] SCSI device sdb: 17781520 512-byte hdwr sectors (9104 MB) [ 66.028252] sdb: Write Protect is off [ 66.035720] SCSI device sdb: write cache: enabled, read cache: enabled, supports DPO and FUA [ 66.044200] sdb: sdb1 [ 66.057330] sd 0:0:2:0: Attached scsi disk sdb [ 66.061838] sd 0:0:2:0: Attached scsi generic sg1 type 0 [ 66.091409] SATA PHY: stable DET=3 [ 61.95984] SATA PHY: stable DET=3 [ 66.300389] SATA PHY: stable DET=3 [ 66.404964] SATA PHY: stable DET=3 [ 66.509409] SATA PHY: stable DET=3 [ 66.612919] SATA PHY: stable DET=3 [ 66.717494] SATA PHY: stable DET=3 [ 66.821899] SATA PHY: stable DET=3 [ 66.926474] SATA PHY: stable DET=3 [ 67.030906] SATA PHY: stable DET=3 [ 67.134430] SATA PHY: stable DET=3 [ 67.239005] SATA PHY: stable DET=3 [ 67.343410] SATA PHY: stable DET=3 [ 67.447985] SATA PHY: stable DET=3 [ 67.552403] SATA PHY: stable DET=3 [ 67.656952] SATA PHY: stable DET=3 [ 67.761528] SATA PHY: stable DET=3 [ 67.865933] SATA PHY: stable DET=3 [ 67.970508] SATA PHY: stable DET=3 [ 68.074926] SATA PHY: stable DET=3 [ 68.083625] SATA PHY: debounced [ 68.242305] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300) [ 98.221334] ata2.00: qc timeout (cmd 0xec) [ 98.225467] ata2.00: failed to IDENTIFY (I/O error, err_mask=0x104) [ 99.035300] SATA PHY: stable DET=3 [ 99.139875] SATA PHY: stable DET=3 [ 99.244281] SATA PHY: stable DET=3 [ 99.348855] SATA PHY: stable DET=3 [ 99.453287] SATA PHY: stable DET=3 [ 99.556811] SATA PHY: stable DET=3 [ 99.661386] SATA PHY: stable DET=3 [ 99.765791] SATA PHY: stable DET=3 [ 99.870366] SATA PHY: stable DET=3 [ 99.974785] SATA PHY: stable DET=3 [ 100.079334] SATA PHY: stable DET=3 [ 100.183909] SATA PHY: stable DET=3 [ 100.288314] SATA PHY: stable DET=3 [ 100.392889] SATA PHY: stable DET=3 [ 100.497308] SATA PHY: stable DET=3 [ 100.601856] SATA PHY: stable DET=3 [ 100.706431] SATA PHY: stable DET=3 [ 100.810837] SATA PHY: stable DET=3 [ 100.915412] SATA PHY: stable DET=3 [ 101.019830] SATA PHY: stable DET=3 [ 101.023263] SATA PHY: debounced [ 108.063137] ata2: port is slow to respond, please be patient (Status 0x80) [ 131.003980] ata2: port failed to respond (30 secs, Status 0x80) [ 131.009930] ata2: COMRESET failed (device not ready) [ 131.014926] ata2: hardreset failed, retrying in 5 secs [ 136.320451] SATA PHY: stable DET=3 [ 136.425026] SATA PHY: stable DET=3 [ 136.529509] SATA PHY: stable DET=3 [ 136.632981] SATA PHY: stable DET=3 [ 136.737556] SATA PHY: stable DET=3 [ 136.841962] SATA PHY: stable DET=3 [ 136.946536] SATA PHY: stable DET=3 [ 137.051007] SATA PHY: stable DET=3 [ 137.154492] SATA PHY: stable DET=3 [ 137.259067] SATA PHY: stable DET=3 [ 137.363472] SATA PHY: stable DET=3 [ 137.468047] SATA PHY: stable DET=3 [ 137.572505] SATA PHY: stable DET=3 [ 137.676002] SATA PHY: stable DET=3 [ 137.780577] SATA PHY: stable DET=3 [ 137.884983] SATA PHY: stable DET=3 [ 137.989558] SATA PHY: stable DET=3 [ 138.094002] SATA PHY: stable DET=3 [ 138.197513] SATA PHY: stable DET=3 [ 138.302088] SATA PHY: stable DET=3 [ 138.305524] SATA PHY: debounced [ 138.308717] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300) [ 138.319554] ata2.00: ATA-6, max UDMA/133, 640 sectors: LBA [ 138.325157] ata2.00: ata2: dev 0 multi count 1 [ 138.334245] ata2.00: configured for UDMA/133 [ 138.338553] scsi3 : ahci [ 138.642450] SATA PHY: stable DET=3 [ 138.746999] SATA PHY: stable DET=3 [ 138.851574] SATA PHY: stable DET=3 [ 138.955979] SATA PHY: stable DET=3 [ 139.060554] SATA PHY: stable DET=3 [ 139.164972] SATA PHY: stable DET=3 [ 139.269521] SATA PHY: stable DET=3 [ 139.374096] SATA PHY: stable DET=3 [ 139.478502] SATA PHY: stable DET=3 [ 139.583077] SATA PHY: stable DET=3 [ 139.687495] SATA PHY: stable DET=3 [ 139.792044] SATA PHY: stable DET=3 [ 139.896619] SATA PHY: stable DET=3 [ 140.001025] SATA PHY: stable DET=3 [ 140.105599] SATA PHY: stable DET=3 [ 140.210018] SATA PHY: stable DET=3 [ 140.314567] SATA PHY: stable DET=3 [ 140.419142] SATA PHY: stable DET=3 [ 140.523547] SATA PHY: stable DET=3 [ 140.628122] SATA PHY: stable DET=3 [ 140.631564] SATA PHY: debounced [ 140.789363] ata3: SATA link up 1.5 Gbps (SStatus 113 SControl 300) [ 140.800879] ata3.00: ATA-7, max UDMA/133, 488397168 sectors: LBA48 NCQ (depth 31/32) [ 140.808662] ata3.00: ata3: dev 0 multi count 16 [ 140.818560] ata3.00: configured for UDMA/133 [ 140.822867] scsi4 : ahci [ 141.126871] SATA PHY: stable DET=0 [ 141.231446] SATA PHY: stable DET=0 [ 141.335852] SATA PHY: stable DET=0 [ 141.440427] SATA PHY: stable DET=0 [ 141.544884] SATA PHY: stable DET=0 [ 141.648369] SATA PHY: stable DET=0 [ 141.752944] SATA PHY: stable DET=0 [ 141.857349] SATA PHY: stable DET=0 [ 141.961924] SATA PHY: stable DET=0 [ 142.066356] SATA PHY: stable DET=0 [ 142.169866] SATA PHY: stable DET=0 [ 142.274428] SATA PHY: stable DET=0 [ 142.378821] SATA PHY: stable DET=0 [ 142.483396] SATA PHY: stable DET=0 [ 142.587801] SATA PHY: stable DET=0 [ 142.692376] SATA PHY: stable DET=0 [ 142.796925] SATA PHY: stable DET=0 [ 142.901331] SATA PHY: stable DET=0 [ 143.005906] SATA PHY: stable DET=0 [ 143.110311] SATA PHY: stable DET=0 [ 143.113748] SATA PHY: debounced [ 143.116927] ata4: SATA link down (SStatus 0 SControl 300) [ 143.122397] scsi 1:0:0:0: Direct-Access ATA WDC WD360GD-00FL 31.0 PQ: 0 ANSI: 5 [ 143.130569] SCSI device sdc: 72303840 512-byte hdwr sectors (37020 MB) [ 143.137134] sdc: Write Protect is off [ 143.140844] SCSI device sdc: write cache: enabled, read cache: enabled, doesn't support DPO or FUA [ 143.149864] SCSI device sdc: 72303840 512-byte hdwr sectors (37020 MB) [ 143.156427] sdc: Write Protect is off [ 143.160136] SCSI device sdc: write cache: enabled, read cache: enabled, doesn't support DPO or FUA [ 143.169136] sdc: sdc1 sdc2 [ 143.181697] sd 1:0:0:0: Attached scsi disk sdc [ 143.186205] sd 1:0:0:0: Attached scsi generic sg2 type 0 [ 143.191590] scsi 2:0:0:0: Direct-Access ATA Config Disk RGL1 PQ: 0 ANSI: 5 [ 143.199761] SCSI device sdd: 640 512-byte hdwr sectors (0 MB) [ 143.205550] sdd: Write Protect is off [ 143.209257] SCSI device sdd: write cache: disabled, read cache: enabled, doesn't support DPO or FUA [ 143.218356] SCSI device sdd: 640 512-byte hdwr sectors (0 MB) [ 143.224143] sdd: Write Protect is off [ 143.227847] SCSI device sdd: write cache: disabled, read cache: enabled, doesn't support DPO or FUA [ 143.236927] sdd: unknown partition table [ 143.241194] sd 2:0:0:0: Attached scsi disk sdd [ 143.245707] sd 2:0:0:0: Attached scsi generic sg3 type 0 [ 143.251093] scsi 3:0:0:0: Direct-Access ATA ST3250823AS 3.03 PQ: 0 ANSI: 5 [ 143.259270] SCSI device sde: 488397168 512-byte hdwr sectors (250059 MB) [ 143.266007] sde: Write Protect is off [ 143.269713] SCSI device sde: write cache: enabled, read cache: enabled, doesn't support DPO or FUA [ 143.278723] SCSI device sde: 488397168 512-byte hdwr sectors (250059 MB) [ 143.285461] sde: Write Protect is off [ 143.289172] SCSI device sde: write cache: enabled, read cache: enabled, doesn't support DPO or FUA [ 143.298165] sde: sde1 sde2 [ 143.313019] sd 3:0:0:0: Attached scsi disk sde [ 143.317525] sd 3:0:0:0: Attached scsi generic sg4 type 0 [ 143.322933] wait_for_probes: waiting for 0 threads [ 143.328340] reiser4: sdc1: found disk format 4.0.0. [ 144.520852] VFS: Mounted root (reiser4 filesystem) readonly. [ 144.526574] Freeing unused kernel memory: 196k freed INIT: version 2.86 booting Starting the hotplug events dispatcher: udevd. Synthesizing the initial hotplug events...done. Waiting for /dev to be fully populated...[ 146.809128] Floppy drive(s): fd0 is 1.44M [ 146.827575] ACPI: PCI Interrupt 0000:02:00.0[A] -> GSI 19 (level, low) -> IRQ 19 [ 146.834248] FDC 0 is a post-1991 82077 [ 146.840305] sky2 v1.10 addr 0xfa9fc000 irq 19 Yukon-EC (0xb6) rev 2 [ 146.846953] sky2 eth0: addr 00:18:f3:3d:1b:06 [ 146.859086] usbcore: registered new interface driver usbfs [ 146.864786] usbcore: registered new interface driver hub [ 146.870281] usbcore: registered new device driver usb [ 146.917589] ACPI: PCI Interrupt 0000:00:1f.3[B] -> GSI 23 (level, low) -> IRQ 23 [ 146.931833] USB Universal Host Controller Interface driver v3.0 [ 146.937929] ACPI: PCI Interrupt 0000:00:1d.0[A] -> GSI 20 (level, low) -> IRQ 20 [ 146.945573] uhci_hcd 0000:00:1d.0: UHCI Host Controller [ 146.946166] ACPI: PCI Interrupt 0000:00:1d.1[B] -> GSI 17 (level, low) -> IRQ 17 [ 146.946174] uhci_hcd 0000:00:1d.1: UHCI Host Controller [ 146.946243] uhci_hcd 0000:00:1d.1: new USB bus registered, assigned bus number 1 [ 146.946271] uhci_hcd 0000:00:1d.1: irq 17, io base 0x0000e800 [ 146.978170] ACPI: PCI Interrupt 0000:00:1d.2[C] -> <6>uhci_hcd 0000:00:1d.0: new USB bus registered, assigned bus number 2 [ 146.983006] usb usb1: new device found, idVendor=0000, idProduct=0000 [ 146.983007] usb usb1: new device strings: Mfr=3, Product=2, SerialNumber=1 [ 146.983009] usb usb1: Product: UHCI Host Controller [ 146.983010] usb usb1: Manufacturer: Linux 2.6.19-rc6-mm1 uhci_hcd [ 146.983011] usb usb1: SerialNumber: 0000:00:1d.1 [ 146.983053] usb usb1: configuration #1 chosen from 1 choice [ 146.983067] hub 1-0:1.0: USB hub found [ 146.983071] hub 1-0:1.0: 2 ports detected [ 147.032637] uhci_hcd 0000:00:1d.0: irq 20, io base 0x0000e480 [ 147.034105] ACPI: PCI Interrupt 0000:00:1d.3[D] -> GSI 19 (level, low) -> IRQ 19 [ 147.034116] uhci_hcd 0000:00:1d.3: UHCI Host Controller [ 147.034135] uhci_hcd 0000:00:1d.3: new USB bus registered, assigned bus number 3 [ 147.034162] uhci_hcd 0000:00:1d.3: irq 19, io base 0x0000ec00 [ 147.034208] usb usb3: new device found, idVendor=0000, idProduct=0000 [ 147.034210] usb usb3: new device strings: Mfr=3, Product=2, SerialNumber=1 [ 147.034211] usb usb3: Product: UHCI Host Controller [ 147.034212] usb usb3: Manufacturer: Linux 2.6.19-rc6-mm1 uhci_hcd [ 147.034213] usb usb3: SerialNumber: 0000:00:1d.3 [ 147.034247] usb usb3: configuration #1 chosen from 1 choice [ 147.034260] hub 3-0:1.0: USB hub found [ 147.034264] hub 3-0:1.0: 2 ports detected [ 147.039065] GSI 18 (level, low) -> IRQ 18 [ 147.039076] uhci_hcd 0000:00:1d.2: UHCI Host Controller [ 147.039096] uhci_hcd 0000:00:1d.2: new USB bus registered, assigned bus number 4 [ 147.039124] uhci_hcd 0000:00:1d.2: irq 18, io base 0x0000e880 [ 147.039172] usb usb4: new device found, idVendor=0000, idProduct=0000 [ 147.039174] usb usb4: new device strings: Mfr=3, Product=2, SerialNumber=1 [ 147.039175] usb usb4: Product: UHCI Host Controller [ 147.039176] usb usb4: Manufacturer: Linux 2.6.19-rc6-mm1 uhci_hcd [ 147.039177] usb usb4: SerialNumber: 0000:00:1d.2 [ 147.039213] usb usb4: configuration #1 chosen from 1 choice [ 147.039227] hub 4-0:1.0: USB hub found [ 147.039230] hub 4-0:1.0: 2 ports detected [ 147.179121] usb usb2: new device found, idVendor=0000, idProduct=0000 [ 147.185797] usb usb2: new device strings: Mfr=3, Product=2, SerialNumber=1 [ 147.192816] usb usb2: Product: UHCI Host Controller [ 147.197824] usb usb2: Manufacturer: Linux 2.6.19-rc6-mm1 uhci_hcd [ 147.204089] usb usb2: SerialNumber: 0000:00:1d.0 [ 147.208847] usb usb2: configuration #1 chosen from 1 choice [ 147.214630] hub 2-0:1.0: USB hub found [ 147.218518] hub 2-0:1.0: 2 ports detected [ 147.226187] ACPI: PCI Interrupt 0000:00:1d.7[A] -> GSI 20 (level, low) -> IRQ 20 [ 147.233789] ehci_hcd 0000:00:1d.7: EHCI Host Controller [ 147.239176] ehci_hcd 0000:00:1d.7: new USB bus registered, assigned bus number 5 [ 147.246785] ehci_hcd 0000:00:1d.7: debug port 1 [ 147.251424] ehci_hcd 0000:00:1d.7: irq 20, io mem 0xfebfbc00 [ 147.261082] ehci_hcd 0000:00:1d.7: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004 [ 147.268797] usb usb5: new device found, idVendor=0000, idProduct=0000 [ 147.275356] usb usb5: new device strings: Mfr=3, Product=2, SerialNumber=1 [ 147.282364] usb usb5: Product: EHCI Host Controller [ 147.287359] usb usb5: Manufacturer: Linux 2.6.19-rc6-mm1 ehci_hcd [ 147.293599] usb usb5: SerialNumber: 0000:00:1d.7 [ 147.298349] usb usb5: configuration #1 chosen from 1 choice [ 147.304096] hub 5-0:1.0: USB hub found [ 147.307971] hub 5-0:1.0: 8 ports detected [ 147.374295] ACPI: PCI Interrupt 0000:00:1b.0[A] -> GSI 19 (level, low) -> IRQ 19 done. [ 147.436111] hda_codec: Unknown model for ALC882, trying auto-probe from BIOS... Setting parameters of disc: (none). Activating swap:swapon on /dev/sdc2 [ 148.355030] usb 5-7: new high speed USB device using ehci_hcd and address 5 [ 148.360570] Adding 1959920k swap on /dev/sdc2. Priority:-1 extents:1 across:1959920k . Will now check root file system:fsck 1.40-WIP (14-Nov-2006) [/sbin/fsck.reiser4 (1) -- /] fsck.reiser4 -a /dev/sdc1 fsck.reiser4 /dev/sdc1 . [ 148.485883] usb 5-7: new device found, idVendor=05e3, idProduct=0606 [ 148.492527] usb 5-7: new device strings: Mfr=0, Product=1, SerialNumber=0 [ 148.499389] usb 5-7: Product: USB2.0 Hub [ 148.503427] usb 5-7: configuration #1 chosen from 1 choice [ 148.509256] hub 5-7:1.0: USB hub found [ 148.513483] hub 5-7:1.0: 4 ports detected Setting the system clock again.. [ 148.693760] usb 2-1: new low speed USB device using uhci_hcd and address 2 [ 148.872577] usb 2-1: new device found, idVendor=045e, idProduct=001e [ 148.879404] usb 2-1: new device strings: Mfr=1, Product=2, SerialNumber=0 [ 148.886640] usb 2-1: Product: Microsoft IntelliMouse® Explorer [ 148.892908] usb 2-1: Manufacturer: Microsoft [ 148.897554] usb 2-1: configuration #1 chosen from 1 choice [ 149.037455] usb 2-2: new low speed USB device using uhci_hcd and address 3 [ 149.202295] usb 2-2: new device found, idVendor=0d3d, idProduct=0001 [ 149.209122] usb 2-2: new device strings: Mfr=0, Product=2, SerialNumber=0 [ 149.216141] usb 2-2: Product: USBPS2 [ 149.220037] usb 2-2: configuration #1 chosen from 1 choice [ 149.381122] usb 4-1: new full speed USB device using uhci_hcd and address 2 System Clock set. Local time: Wed Nov 29 10:00:33 MST 2006. Cleaning up ifupdown.... [ 149.501470] usb 4-1: device descriptor read/64, error -71 Loading kernel module nvidia. [ 149.720180] usb 4-1: device descriptor read/64, error -71 [ 149.928721] usb 4-1: new full speed USB device using uhci_hcd and address 3 [ 150.049658] usb 4-1: device descriptor read/64, error -71 [ 150.247906] nvidia: module license 'NVIDIA' taints kernel. [ 150.270965] usb 4-1: device descriptor read/64, error -71 [ 150.479770] usb 4-1: new full speed USB device using uhci_hcd and address 4 [ 150.518463] NVRM: The NVIDIA probe routine was not called for 1 device(s). [ 150.518480] ACPI: PCI Interrupt 0000:04:00.0[A] -> GSI 16 (level, low) -> IRQ 16 [ 150.533044] NVRM: This can occur when a driver such as rivafb, nvidiafb or [ 150.533045] NVRM: rivatv was loaded and obtained ownership of the NVIDIA [ 150.533045] NVRM: device(s). [ 150.549869] NVRM: Try unloading the rivafb, nvidiafb or rivatv kernel module [ 150.549870] NVRM: (and/or reconfigure your kernel without rivafb/nvidiafb [ 150.549871] NVRM: support), then try loading the NVIDIA kernel module again. [ 150.571210] NVRM: loading NVIDIA Linux x86_64 Kernel Module 1.0-9629 Wed Nov 1 19:27:33 PST 2006 Loading kernel module loop. FATAL: Module loop not found. Loading kernel module i2c-i801. Loading kernel module i2c-isa. Loading kernel module eeprom. Loading kernel module w83627ehf. Loading kernel module usb-storage. [ 150.664559] Initializing USB Mass Storage driver... [ 150.895018] usb 4-1: device not accepting address 4, error -71 [ 151.003603] usb 4-1: new full speed USB device using uhci_hcd and address 5 [ 151.419585] usb 4-1: device not accepting address 5, error -71 [ 151.594459] usb 5-7.3: new high speed USB device using ehci_hcd and address 6 [ 151.688505] usbcore: registered new interface driver hiddev [ 151.699581] usb 5-7.3: new device found, idVendor=0bda, idProduct=8187 [ 151.706515] usb 5-7.3: new device strings: Mfr=1, Product=2, SerialNumber=3 [ 151.713541] usb 5-7.3: Product: RTL8187_Wireless [ 151.718277] usb 5-7.3: Manufacturer: Manufacturer_Realtek_RTL8187_ [ 151.718620] input: Microsoft Microsoft IntelliMouse® Explorer as /class/input/input3 [ 151.718638] input: USB HID v1.00 Mouse [Microsoft Microsoft IntelliMouse® Explorer] on usb-0000:00:1d.0-1 [ 151.742225] usb 5-7.3: SerialNumber: 0015AF05C9DE [ 151.747108] usb 5-7.3: configuration #1 chosen from 1 choice [ 151.753075] input: USBPS2 as /class/input/input4 [ 151.757857] input: USB HID v1.00 Keyboard [USBPS2] on usb-0000:00:1d.0-2 [ 151.786051] input: USBPS2 as /class/input/input5 [ 151.790807] input: USB HID v1.00 Mouse [USBPS2] on usb-0000:00:1d.0-2 [ 151.797467] usbcore: registered new interface driver usbhid [ 151.800788] usbcore: registered new interface driver usb-storage [ 151.800790] USB Mass Storage support registered. [ 151.814017] drivers/usb/input/hid-core.c: v2.6:USB HID core driver Loading kernel module snd-rtctimer. Loading kernel module uhci-hcd. Loading kernel module acpi-cpufreq. FATAL: Error inserting acpi_cpufreq (/lib/modules/2.6.19-rc6-mm1/kernel/arch/x86_64/kernel/cpufreq/acpi-cpufreq.[ 151.898367] usbcore: registered new interface driver cdc_acm ko): No such dev[ 151.905240] drivers/usb/class/cdc-acm.c: v0.25:USB Abstract Control Model driver for USB modems and ISDN adapters ice Loading kernel module cdc-acm. Loading device-mapper support. Will now check all file systems. fsck 1.40-WIP (14-Nov-2006) Checking all file systems. Done checking file systems. A log is being saved in /var/log/fsck/checkfs if that location is writable. Setting kernel variables...done. Will now mount local filesystems:[ 152.069508] ReiserFS: sde1: found reiserfs format "3.6" with standard journal [ 152.076801] ReiserFS: sde1: using ordered data mode [ 152.085742] ReiserFS: sde1: journal params: device sde1, size 8192, journal first block 18, max trans len 1024, max batch 900, max commit age 30, max trans age 30 [ 152.100843] ReiserFS: sde1: checking transaction log (sde1) [ 164.600198] ReiserFS: sde1: replayed 794 transactions in 12 seconds [ 164.669534] ReiserFS: sde1: Using r5 hash to sort names [ 164.738095] reiser4: sda1: found disk format 4.0.0. . Will now activate swapfile swap:done. Cleaning /tmp...done. Cleaning /var/run...done. Cleaning /var/lock...done. Setting up networking.... Configuring network interfaces...done. Starting portmap daemon.... [ 166.539376] sky2 eth0: enabling interface Setting sensors limits: done. Setting console screen modes and fonts. Setting up ALSA...done. Initializing random number generator...done. Recovering nvi editor sessions...none found. Setting up X server socket directory /tmp/.X11-unix.... Setting up ICE socket directory /tmp/.ICE-unix.... Recovering schroot sessions... done. INIT: Entering runlevel: 2 Starting system log daemon.... Starting kernel log daemon.... Loading ACPI modules: Starting Advanced Configuration and Power Interface daemon: acpid. Starting Common Unix Printing System: cupsd[ 168.987188] sky2 eth0: Link is up at 1000 Mbps, full duplex, flow control both . Starting system message bus: dbus. Starting Hardware abstraction layer: hald. Starting DirMngr: dirmngr. Starting mouse interface server: gpm. Starting internet superserver: inetd. Starting Postfix Mail Transport Agent: postfix. Starting Samba daemons: nmbd smbd. Starting sensor daemon: sensord. Starting OpenBSD Secure Shell server: sshd. Setting up X font server socket directory /tmp/.font-unix...done. Starting X font server: xfs. Starting NFS common utilities: statd. Starting NTP server: ntpd. Starting deferred execution scheduler: atd. Starting periodic command scheduler: crond. Starting K Display Manager: kdm. Running local boot scripts (/etc/rc.local). Debian GNU/Linux 4.0 luna ttyS0 luna login: INStopping K Display Manager: kdm. Stopping deferred execution scheduler: atd. Stopping periodic command scheduler: crond. Stopping Samba daemons: nmbd smbd. Stopping Advanced Configuration and Power Interface daemon: acpid. Stopping Common Unix Printing System: cupsd. Stopping Hardware abstraction layer: hald. Stopping system message bus: dbus. Stopping DirMngr: dirmngr. Stopping mouse interface server: gpm. Stopping internet superserver: inetd. Stopping Postfix Mail Transport Agent: postfix. Stopping sensor daemon: sensord. Stopping OpenBSD Secure Shell server: sshd. Stopping X font server: xfs. Stopping NTP server: ntpd. Saving the system clock.. Hardware Clock updated to Wed Nov 29 10:18:57 MST 2006. Shutting down ALSA...done. Stopping NFS common utilities: statd. Stopping kernel log daemon.... Stopping system log daemon.... Asking all remaining processes to terminate...done. Killing all remaining processes...done. Saving random seed...done. Unmounting remote and non-toplevel virtual filesystems...done. Stopping portmap daemon.... Deconfiguring network interfaces...[ 1256.730223] sky2 eth0: disabling interface done. Cleaning up ifupdown.... Will now unmount temporary filesystems:/dev umounted . Will now deactivate swap:swapoff on /dev/sdc2 . Will now unmount local filesystems:/backup umounted /home umounted /tmp umounted /dev/sde1 umounted /dev/sda1 umounted /dev/hde1 umounted . Mounting root filesystem read-only...done. Will now halt. [ 1263.282362] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 [ 1263.288935] ata2.00: (irq_stat 0x40000001) [ 1263.293132] ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/00 tag 0 data 0 in [ 1263.293133] res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error) [ 1263.317596] ata2.00: configured for UDMA/133 [ 1263.321960] ata2: EH complete [ 1263.325033] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 [ 1263.331612] ata2.00: (irq_stat 0x40000001) [ 1263.335793] ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/00 tag 0 data 0 in [ 1263.335794] res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error) [ 1263.360185] ata2.00: configured for UDMA/133 [ 1263.364560] ata2: EH complete [ 1263.367633] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 [ 1263.374188] ata2.00: (irq_stat 0x40000001) [ 1263.378388] ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/00 tag 0 data 0 in [ 1263.378389] res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error) [ 1263.402797] ata2.00: configured for UDMA/133 [ 1263.407169] ata2: EH complete [ 1263.410243] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 [ 1263.416817] ata2.00: (irq_stat 0x40000001) [ 1263.421006] ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/00 tag 0 data 0 in [ 1263.421007] res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error) [ 1263.445412] ata2.00: configured for UDMA/133 [ 1263.449788] ata2: EH complete [ 1263.452853] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 [ 1263.459427] ata2.00: (irq_stat 0x40000001) [ 1263.463599] ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/00 tag 0 data 0 in [ 1263.463600] res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error) [ 1263.488009] ata2.00: configured for UDMA/133 [ 1263.492381] ata2: EH complete [ 1263.495444] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 [ 1263.502025] ata2.00: (irq_stat 0x40000001) [ 1263.506218] ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/00 tag 0 data 0 in [ 1263.506219] res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error) [ 1263.530601] ata2.00: configured for UDMA/133 [ 1263.534976] ata2: EH complete [ 1263.538045] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 [ 1263.544629] ata2.00: (irq_stat 0x40000001) [ 1263.548829] ata2.00: cmd 94/00:00:00:00:00/00:00:00:00:00/00 tag 0 data 0 in [ 1263.548830] res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error) [ 1263.573221] ata2.00: configured for UDMA/133 [ 1263.577602] ata2: EH complete [ 1263.580665] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 [ 1263.587239] ata2.00: (irq_stat 0x40000001) [ 1263.591438] ata2.00: cmd 94/00:00:00:00:00/00:00:00:00:00/00 tag 0 data 0 in [ 1263.591439] res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error) [ 1263.615862] ata2.00: configured for UDMA/133 [ 1263.620229] ata2: EH complete [ 1263.623311] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 [ 1263.629868] ata2.00: (irq_stat 0x40000001) [ 1263.634065] ata2.00: cmd 94/00:00:00:00:00/00:00:00:00:00/00 tag 0 data 0 in [ 1263.634066] res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error) [ 1263.658447] ata2.00: configured for UDMA/133 [ 1263.662833] ata2: EH complete [ 1263.665895] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 [ 1263.672469] ata2.00: (irq_stat 0x40000001) [ 1263.676667] ata2.00: cmd 94/00:00:00:00:00/00:00:00:00:00/00 tag 0 data 0 in [ 1263.676668] res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error) [ 1263.701069] ata2.00: configured for UDMA/133 [ 1263.705441] ata2: EH complete [ 1263.708497] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 [ 1263.715071] ata2.00: (irq_stat 0x40000001) [ 1263.719259] ata2.00: cmd 94/00:00:00:00:00/00:00:00:00:00/00 tag 0 data 0 in [ 1263.719260] res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error) [ 1263.743678] ata2.00: configured for UDMA/133 [ 1263.748061] ata2: EH complete [ 1263.751134] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 [ 1263.757708] ata2.00: (irq_stat 0x40000001) [ 1263.761887] ata2.00: cmd 94/00:00:00:00:00/00:00:00:00:00/00 tag 0 data 0 in [ 1263.761888] res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error) [ 1263.786297] ata2.00: configured for UDMA/133 [ 1263.790672] ata2: EH complete [ 1263.793738] SCSI device sdd: 640 512-byte hdwr sectors (0 MB) [ 1263.795912] Synchronizing SCSI cache for disk sde: [ 1263.804598] sdd: Write Protect is off [ 1263.808358] SCSI device sdd: write cache: disabled, read cache: enabled, doesn't support DPO or FUA [ 1263.817575] SCSI device sdd: 640 512-byte hdwr sectors (0 MB) [ 1263.823445] sdd: Write Protect is off [ 1263.827208] SCSI device sdd: write cache: disabled, read cache: enabled, doesn't support DPO or FUA [ 1263.838496] Synchronizing SCSI cache for disk sdc: [ 1263.843632] Synchronizing SCSI cache for disk sdb: [ 1263.848871] Synchronizing SCSI cache for disk sda: [ 1264.345916] Shutdown: hdg [ 1264.348810] Shutdown: hde [ 1264.352044] Power down. [ 1264.354633] acpi_power_off called ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: 2.6.18 - AHCI detection pauses excessively 2006-11-29 18:53 ` Berck E. Nash @ 2006-11-29 19:27 ` Mark Lord 2006-12-01 7:07 ` Tejun Heo 1 sibling, 0 replies; 12+ messages in thread From: Mark Lord @ 2006-11-29 19:27 UTC (permalink / raw) To: Berck E. Nash Cc: Tejun Heo, linux-kernel@vger.kernel.org, linux-ide@vger.kernel.org Berck E. Nash wrote: > Tejun Heo wrote: > >> Then, a series of obsolete STANDBY failures. Who's issuing these >> commands? It's not libata, libata uses STANDBY (0xe2). Is it some >> kind of gentoo thing? > > Nope, Debian/Unstable. Most probably my hdparm utility. It first tries the old STANDBY command, then tries the newer one if the first one fails. This should not cause anybody's system to lock up. Cheers ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: 2.6.18 - AHCI detection pauses excessively 2006-11-29 18:53 ` Berck E. Nash 2006-11-29 19:27 ` Mark Lord @ 2006-12-01 7:07 ` Tejun Heo 2006-12-01 13:35 ` Berck E. Nash 1 sibling, 1 reply; 12+ messages in thread From: Tejun Heo @ 2006-12-01 7:07 UTC (permalink / raw) To: Berck E. Nash; +Cc: linux-kernel@vger.kernel.org, linux-ide@vger.kernel.org Berck E. Nash wrote: > [ 68.242305] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300) > [ 98.221334] ata2.00: qc timeout (cmd 0xec) > [ 98.225467] ata2.00: failed to IDENTIFY (I/O error, err_mask=0x104) > [ 108.063137] ata2: port is slow to respond, please be patient (Status 0x80) > [ 131.003980] ata2: port failed to respond (30 secs, Status 0x80) > [ 131.009930] ata2: COMRESET failed (device not ready) > [ 131.014926] ata2: hardreset failed, retrying in 5 secs > [ 138.308717] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300) > [ 138.319554] ata2.00: ATA-6, max UDMA/133, 640 sectors: LBA > [ 138.325157] ata2.00: ata2: dev 0 multi count 1 > [ 138.334245] ata2.00: configured for UDMA/133 [--snip--] > [ 143.191590] scsi 2:0:0:0: Direct-Access ATA Config Disk RGL1 PQ: 0 ANSI: 5 > [ 143.199761] SCSI device sdd: 640 512-byte hdwr sectors (0 MB) > [ 143.205550] sdd: Write Protect is off > [ 143.209257] SCSI device sdd: write cache: disabled, read cache: enabled, doesn't support DPO or FUA > [ 143.218356] SCSI device sdd: 640 512-byte hdwr sectors (0 MB) > [ 143.224143] sdd: Write Protect is off > [ 143.227847] SCSI device sdd: write cache: disabled, read cache: enabled, doesn't support DPO or FUA > [ 143.236927] sdd: unknown partition table > [ 143.241194] sd 2:0:0:0: Attached scsi disk sdd > [ 143.245707] sd 2:0:0:0: Attached scsi generic sg3 type 0 Ahh.. I can't believe I missed this again. A Port Multiplier is attached to your ata2 which is probably a sil3726 or 4726. Why this device fails initial reset is unknown yet. Anyways, with proper PMP support, this problem will go away. So, this isn't really a ahci issue and there's nothing wrong with your disks either. I'll ask SIMG why this happens with the PMP. -- tejun ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: 2.6.18 - AHCI detection pauses excessively 2006-12-01 7:07 ` Tejun Heo @ 2006-12-01 13:35 ` Berck E. Nash 2006-12-01 13:59 ` Tejun Heo 0 siblings, 1 reply; 12+ messages in thread From: Berck E. Nash @ 2006-12-01 13:35 UTC (permalink / raw) To: Tejun Heo; +Cc: linux-kernel@vger.kernel.org, linux-ide@vger.kernel.org Tejun Heo wrote: > Berck E. Nash wrote: >> [ 68.242305] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300) >> [ 98.221334] ata2.00: qc timeout (cmd 0xec) >> [ 98.225467] ata2.00: failed to IDENTIFY (I/O error, err_mask=0x104) >> [ 108.063137] ata2: port is slow to respond, please be patient (Status 0x80) >> [ 131.003980] ata2: port failed to respond (30 secs, Status 0x80) >> [ 131.009930] ata2: COMRESET failed (device not ready) >> [ 131.014926] ata2: hardreset failed, retrying in 5 secs >> [ 138.308717] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300) >> [ 138.319554] ata2.00: ATA-6, max UDMA/133, 640 sectors: LBA >> [ 138.325157] ata2.00: ata2: dev 0 multi count 1 >> [ 138.334245] ata2.00: configured for UDMA/133 > [--snip--] >> [ 143.191590] scsi 2:0:0:0: Direct-Access ATA Config Disk RGL1 PQ: 0 ANSI: 5 >> [ 143.199761] SCSI device sdd: 640 512-byte hdwr sectors (0 MB) >> [ 143.205550] sdd: Write Protect is off >> [ 143.209257] SCSI device sdd: write cache: disabled, read cache: enabled, doesn't support DPO or FUA >> [ 143.218356] SCSI device sdd: 640 512-byte hdwr sectors (0 MB) >> [ 143.224143] sdd: Write Protect is off >> [ 143.227847] SCSI device sdd: write cache: disabled, read cache: enabled, doesn't support DPO or FUA >> [ 143.236927] sdd: unknown partition table >> [ 143.241194] sd 2:0:0:0: Attached scsi disk sdd >> [ 143.245707] sd 2:0:0:0: Attached scsi generic sg3 type 0 > > Ahh.. I can't believe I missed this again. A Port Multiplier is > attached to your ata2 which is probably a sil3726 or 4726. Why this > device fails initial reset is unknown yet. Anyways, with proper PMP > support, this problem will go away. So, this isn't really a ahci issue > and there's nothing wrong with your disks either. I'll ask SIMG why > this happens with the PMP. Hrm. It's not a Silicon Image chip, or at least doesn't claim to be: 00:1f.2 SATA controller: Intel Corporation 82801GR/GH (ICH7 Family) Serial ATA Storage Controller AHCI (rev 01) (prog-if 01 [AHCI 1.0]) Subsystem: ASUSTeK Computer Inc. Unknown device 2606 Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- Status: Cap+ 66MHz+ UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- Latency: 0 Interrupt: pin B routed to IRQ 316 Region 0: I/O ports at e400 [size=8] Region 1: I/O ports at e080 [size=4] Region 2: I/O ports at e000 [size=8] Region 3: I/O ports at dc00 [size=4] Region 4: I/O ports at d880 [size=16] Region 5: Memory at febfb800 (32-bit, non-prefetchable) [size=1K] Capabilities: [80] Message Signalled Interrupts: Mask- 64bit- Queue=0/0 Enable+ Address: fee0300c Data: 4179 Capabilities: [70] Power Management version 2 Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA PME(D0-,D1-,D2-,D3hot+,D3cold-) Status: D0 PME-Enable- DSel=0 DScale=0 PME- And, remember, this behavior started in 2.6.18 and didn't exist in 2.6.17. Would it help if I narrowed down which patch caused it? Berck ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: 2.6.18 - AHCI detection pauses excessively 2006-12-01 13:35 ` Berck E. Nash @ 2006-12-01 13:59 ` Tejun Heo 0 siblings, 0 replies; 12+ messages in thread From: Tejun Heo @ 2006-12-01 13:59 UTC (permalink / raw) To: Berck E. Nash; +Cc: linux-kernel@vger.kernel.org, linux-ide@vger.kernel.org Berck E. Nash wrote: > Hrm. It's not a Silicon Image chip, or at least doesn't claim to be: Yeap, the controller is ich ahci but I'm pretty sure there's a PMP chip connected to one of them. Look for 4723 in the following page. http://www.asus.com/products4.aspx?modelmenu=2&model=1198&l1=3&l2=11&l3=248 > 00:1f.2 SATA controller: Intel Corporation 82801GR/GH (ICH7 Family) > Serial ATA Storage Controller AHCI (rev 01) (prog-if 01 [AHCI 1.0]) > Subsystem: ASUSTeK Computer Inc. Unknown device 2606 > Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- > ParErr- Stepping- SERR- FastB2B- > Status: Cap+ 66MHz+ UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- > <TAbort- <MAbort- >SERR- <PERR- > Latency: 0 > Interrupt: pin B routed to IRQ 316 > Region 0: I/O ports at e400 [size=8] > Region 1: I/O ports at e080 [size=4] > Region 2: I/O ports at e000 [size=8] > Region 3: I/O ports at dc00 [size=4] > Region 4: I/O ports at d880 [size=16] > Region 5: Memory at febfb800 (32-bit, non-prefetchable) [size=1K] > Capabilities: [80] Message Signalled Interrupts: Mask- 64bit- > Queue=0/0 Enable+ > Address: fee0300c Data: 4179 > Capabilities: [70] Power Management version 2 > Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA > PME(D0-,D1-,D2-,D3hot+,D3cold-) > Status: D0 PME-Enable- DSel=0 DScale=0 PME- > > And, remember, this behavior started in 2.6.18 and didn't exist in > 2.6.17. Would it help if I narrowed down which patch caused it? Yeah, that's probably because we're now using IRQ-driven PIO for IDENTIFY, so we're often slower at detecting IDENTIFY failure. We're planning to go back to polling IDENTIFY. Anyways, the problem here is that the 4723 is emulating ATA device for configuration but it isn't doing it quite right. I'll ask SIMG about it. -- tejun ^ permalink raw reply [flat|nested] 12+ messages in thread
end of thread, other threads:[~2006-12-01 13:59 UTC | newest] Thread overview: 12+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2006-11-13 0:09 2.6.18 - AHCI detection pauses excessively Berck E. Nash 2006-11-15 12:45 ` Tejun Heo 2006-11-15 18:22 ` Berck E. Nash 2006-11-23 11:20 ` JG 2006-11-27 3:35 ` Tejun Heo 2006-11-27 8:58 ` Berck E. Nash 2006-11-29 8:55 ` Tejun Heo 2006-11-29 18:53 ` Berck E. Nash 2006-11-29 19:27 ` Mark Lord 2006-12-01 7:07 ` Tejun Heo 2006-12-01 13:35 ` Berck E. Nash 2006-12-01 13:59 ` Tejun Heo
This is an external index of several public inboxes, see mirroring instructions on how to clone and mirror all data and code used by this external index.