Bug 7500

Summary: Libata ALi driver boot failure
Product: IO/Storage Reporter: Jack Byer (ojbyer)
Component: Serial ATAAssignee: Alan (alan)
Status: CLOSED OBSOLETE    
Severity: normal CC: alan, albertcc, arvidjaar, bunk, frederik, htejun, sero4linux
Priority: P2    
Hardware: i386   
OS: Linux   
Kernel Version: 2.6.25-rc4 Subsystem:
Regression: No Bisected commit-id:
Attachments: force-pio-on-dw224e.patch
dmesg, lspci, hdparm and cdrecord for pata and ide
dmesg with pata_ali from 2.6.25-rc4

Description Jack Byer 2006-11-12 08:14:47 UTC
Most recent kernel where this bug did not occur: unknown
Distribution: Gentoo
Hardware Environment: hp pavilion ze4400 laptop

00:10.0 IDE interface: ALi Corporation M5229 IDE (rev c4)

Problem Description:

I tried to use the experimental ali libata driver for the first time, but I am
unable to boot with it. The driver tries several times to bring up the harware,
but ultimately fails. I am then unable to boot because I can't find the hard
drive. Is there any information I can provide that would be useful for development?
Comment 1 Alan 2006-11-12 10:35:33 UTC
Please provide the messages it prints as it boots, that seem to lead to the
failure (or attach a jpg of a screenshot if thats easier)
Comment 2 Jack Byer 2006-11-12 19:00:27 UTC
The hard drive seems to detect ok, but the problem starts with the CDROM
I took a picture on my phone, then tried to transcribe as much as I can:

ata1.00: PATA max UDMA/133 cmd 0x1F0 ctl 0x3F6 <unreadable>
ata1.00: PATA max UDMA/133 cmd 0x170 ctl 0x376 <unreadable>
scsi0 : pata_ali
ata1.00: ATA-6, MAX UDMA/100 195371560 sectors LBA
ata1.00: ata1: dev 0 multi count 16
ata1.00: configured for UDMA/100
scsi1 : pata_ali
ata12.00: ATAPI, max MWDMA2 
ata12.00: Configured for MWDMA2
scsi 0:0:0:0: Direct-Access         ATA  <unreadable>

ata12.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 (frozen)
ata12.00: (BMDMA stat 0x1)*
ata12.00: tag 0 cmd 0xa0 Emask 0x4 stat 0x40 err 0x0 (timeout)
ata12: soft resetting port
ata12.00: configured for MWDMA2
ata2: EH complete

These lines repeat for a while then give up. The kernel continues loading until
it get the point of mounting the root device.

After the lernel fails to find the root device, the following error repeats
indefinately while the capslock light flashes:

atkbd.c: Spurious ACK on isa0060/serio0. Some program might be trying to access
hardware directly.
Comment 3 Alan 2006-11-13 03:13:44 UTC
Ok the CD problem is known. The keyboard one appears to be new and needs
reporting. Can you add another bug about the keyboard message that keeps repeating.

For the ATAPI problem I'm hoping Tejun's work on the EH will fix it - right now
most ATAPI is broken unless you back out the improved error handling patches.
Comment 4 Dmitry Torokhov 2006-11-16 19:39:49 UTC
Keyboard problem is most likely panic blink in action.
Comment 5 Alan 2007-06-18 09:19:35 UTC
Multiple ali fixes in 2.6.22-rc5
Comment 6 Jack Byer 2007-06-18 18:03:23 UTC
(In reply to comment #5)
> Multiple ali fixes in 2.6.22-rc5
> 

I'll compile this kernel and test it tonight or tomorrow.
Comment 7 Jack Byer 2007-06-21 17:25:40 UTC
(In reply to comment #5)
> Multiple ali fixes in 2.6.22-rc5
> 

There is no change in symptoms with this kernel from the previous time I tried it.
Comment 8 Jack Byer 2007-07-04 17:09:23 UTC
I've tried 2.6.22-rc7, and it still doesn't work, but some magic with initramfs and static ssh let me capture the dmesg output:

00003bf00000 (ACPI NVS)
 BIOS-e820: 000000003bf00000 - 000000003c000000 (reserved)
 BIOS-e820: 00000000fffc0000 - 0000000100000000 (reserved)
62MB HIGHMEM available.
896MB LOWMEM available.
Entering add_active_range(0, 0, 245488) 0 entries of 256 used
Zone PFN ranges:
  DMA             0 ->     4096
  Normal       4096 ->   229376
  HighMem    229376 ->   245488
early_node_map[1] active PFN ranges
    0:        0 ->   245488
On node 0 totalpages: 245488
  DMA zone: 32 pages used for memmap
  DMA zone: 0 pages reserved
  DMA zone: 4064 pages, LIFO batch:0
  Normal zone: 1760 pages used for memmap
  Normal zone: 223520 pages, LIFO batch:31
  HighMem zone: 125 pages used for memmap
  HighMem zone: 15987 pages, LIFO batch:3
DMI 2.3 present.
ACPI: RSDP 000F72B0, 0014 (r0 PTLTD )
ACPI: RSDT 3BEF8CCA, 0030 (r1 PTLTD    RSDT    6040000  LTP        0)
ACPI: FACP 3BEFEE2B, 0074 (r1 ATI    Raptor    6040000 ATI     F4240)
ACPI: DSDT 3BEF8CFA, 6131 (r1    ATI U1_M1535  6040000 MSFT  100000D)
ACPI: FACS 3BEFFFC0, 0040
ACPI: BOOT 3BEFEE9F, 0028 (r1 PTLTD  $SBFTBL$  6040000  LTP        1)
ACPI: SSDT 3BEFEEC7, 0139 (r1 PTLTD  POWERNOW  6040000  LTP        1)
ATI board detected. Disabling timer routing over 8254.
ACPI: PM-Timer IO Port: 0x8008
Allocating PCI resources starting at 40000000 (gap: 3c000000:c3fc0000)
Built 1 zonelists.  Total pages: 243571
Kernel command line: video=radeonfb:1024x768-32@80
Local APIC disabled by BIOS -- you can enable it with "lapic"
mapped APIC to ffffd000 (020fc000)
Enabling fast FPU save and restore... done.
Enabling unmasked SIMD FPU exception support... done.
Initializing CPU#0
PID hash table entries: 4096 (order: 12, 16384 bytes)
Detected 1788.970 MHz processor.
Console: colour VGA+ 80x25
Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
Memory: 943720k/981952k available (3088k kernel code, 37632k reserved, 828k data, 20872k init, 64448k highmem)
virtual kernel memory layout:
    fixmap  : 0xfffaa000 - 0xfffff000   ( 340 kB)
    pkmap   : 0xff800000 - 0xffc00000   (4096 kB)
    vmalloc : 0xf8800000 - 0xff7fe000   ( 111 MB)
    lowmem  : 0xc0000000 - 0xf8000000   ( 896 MB)
      .init : 0xc04d6000 - 0xc1938000   (20872 kB)
      .data : 0xc04042f7 - 0xc04d33dc   ( 828 kB)
      .text : 0xc0100000 - 0xc04042f7   (3088 kB)
Checking if this processor honours the WP bit even in supervisor mode... Ok.
Calibrating delay using timer specific routine.. 3578.58 BogoMIPS (lpj=1789290)
Mount-cache hash table entries: 512
CPU: After generic identify, caps: 0383f9ff c1cbf9ff 00000000 00000000 00000000 00000000 00000000
CPU: L1 I Cache: 64K (64 bytes/line), D cache 64K (64 bytes/line)
CPU: L2 Cache: 512K (64 bytes/line)
CPU: After all inits, caps: 0383f9ff c1cbf9ff 00000000 00000420 00000000 00000000 00000000
Intel machine check architecture supported.
Intel machine check reporting enabled on CPU#0.
Compat vDSO mapped to ffffe000.
CPU: AMD mobile AMD Athlon(tm) XP2400+ stepping 00
Checking 'hlt' instruction... OK.
ACPI: Core revision 20070126
ACPI: setting ELCR to 0200 (from 0e28)
NET: Registered protocol family 16
ACPI: bus type pci registered
PCI: PCI BIOS revision 2.10 entry at 0xfd87b, last bus=2
PCI: Using configuration type 1
Setting up standard PCI resources
ACPI: Interpreter enabled
ACPI: (supports S0 S3 S4 S5)
ACPI: Using PIC for interrupt routing
ACPI: PCI Root Bridge [PCI0] (0000:00)
PCI: Probing PCI hardware (bus 00)
PCI quirk: region 8000-803f claimed by ali7101 ACPI
PCI quirk: region 8040-805f claimed by ali7101 SMB
ACPI: PCI Interrupt Routing Table [\_SB_.PCI0._PRT]
ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.AGPB._PRT]
ACPI: PCI Interrupt Link [LNKA] (IRQs 3 4 6 *10)
ACPI: PCI Interrupt Link [LNKB] (IRQs 7 *11)
ACPI: PCI Interrupt Link [LNKC] (IRQs 3 4 6 10) *9
ACPI: PCI Interrupt Link [LNKD] (IRQs 3 4 6 *10)
ACPI: PCI Interrupt Link [LNKE] (IRQs 3 4 6 10) *0, disabled.
ACPI: PCI Interrupt Link [LNKF] (IRQs 7 *11)
ACPI: PCI Interrupt Link [LNKG] (IRQs *3 4 6 10)
ACPI: PCI Interrupt Link [LNKH] (IRQs *5 7)
ACPI: PCI Interrupt Link [LNKU] (IRQs 3 4 6 10) *9
Linux Plug and Play Support v0.97 (c) Adam Belay
pnp: PnP ACPI init
ACPI: bus type pnp registered
pnp: PnP ACPI: found 11 devices
ACPI: ACPI bus type pnp unregistered
SCSI subsystem initialized
libata version 2.21 loaded.
usbcore: registered new interface driver usbfs
usbcore: registered new interface driver hub
usbcore: registered new device driver usb
PCI: Using ACPI for IRQ routing
PCI: If a device doesn't work, try "pci=routeirq".  If it helps, post a report
pnp: 00:07: ioport range 0x40b-0x40b has been reserved
pnp: 00:07: ioport range 0x480-0x48f has been reserved
pnp: 00:07: ioport range 0x4d0-0x4d1 has been reserved
pnp: 00:07: ioport range 0x4d6-0x4d6 has been reserved
pnp: 00:07: ioport range 0x8000-0x807f could not be reserved
pnp: 00:07: iomem range 0xe0500000-0xe0500fff has been reserved
Time: tsc clocksource has been installed.
pnp: 00:07: iomem range 0xd0500000-0xd0500fff has been reserved
PCI: Bridge: 0000:00:01.0
  IO window: 9000-9fff
  MEM window: d0100000-d01fffff
  PREFETCH window: e0000000-efffffff
PCI: Bus 2, cardbus bridge: 0000:00:0a.0
  IO window: 00001000-000010ff
  IO window: 00001400-000014ff
  PREFETCH window: 40000000-43ffffff
  MEM window: 44000000-47ffffff
ACPI: PCI Interrupt Link [LNKF] enabled at IRQ 11
PCI: setting IRQ 11 as level-triggered
ACPI: PCI Interrupt 0000:00:0a.0[A] -> Link [LNKF] -> GSI 11 (level, low) -> IRQ 11
NET: Registered protocol family 2
IP route cache hash table entries: 32768 (order: 5, 131072 bytes)
TCP established hash table entries: 131072 (order: 8, 1048576 bytes)
TCP bind hash table entries: 65536 (order: 6, 262144 bytes)
TCP: Hash tables configured (established 131072 bind 65536)
TCP reno registered
Switched to high resolution mode on CPU 0
Simple Boot Flag at 0x36 set to 0x1
Machine check exception polling timer started.
highmem bounce pool size: 64 pages
Total HugeTLB memory allocated, 0
SGI XFS with ACLs, security attributes, realtime, large block numbers, no debug enabled
SGI XFS Quota Management subsystem
Registering unionfs 2.0
io scheduler noop registered
io scheduler cfq registered (default)
ATI Northbridge, reserving I/O ports 0x3b0 to 0x3bb.
Activating ISA DMA hang workarounds.
Boot video device is 0000:01:05.0
ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 10
PCI: setting IRQ 10 as level-triggered
ACPI: PCI Interrupt 0000:01:05.0[A] -> Link [LNKC] -> GSI 10 (level, low) -> IRQ 10
PCI: Unable to reserve mem region #1:10000000@e0000000 for device 0000:01:05.0
radeonfb (0000:01:05.0): cannot request region 0.
radeonfb: probe of 0000:01:05.0 failed with error -16
Real Time Clock Driver v1.12ac
Linux agpgart interface v0.102 (c) Dave Jones
Hangcheck: starting hangcheck timer 0.9.0 (tick is 180 seconds, margin is 60 seconds).
Hangcheck: Using get_cycles().
Serial: 8250/16550 driver $Revision: 1.90 $ 4 ports, IRQ sharing disabled
00:0a: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
ACPI: PCI Interrupt Link [LNKG] enabled at IRQ 3
PCI: setting IRQ 3 as level-triggered
ACPI: PCI Interrupt 0000:00:08.0[A] -> Link [LNKG] -> GSI 3 (level, low) -> IRQ 3
0000:00:08.0: ttyS1 at I/O 0x8828 (irq = 3) is a 8250
0000:00:08.0: ttyS2 at I/O 0x8840 (irq = 3) is a 8250
0000:00:08.0: ttyS3 at I/O 0x8850 (irq = 3) is a 8250
Couldn't register serial port 0000:00:08.0: -28
RAMDISK driver initialized: 16 RAM disks of 4096K size 1024 blocksize
loop: module loaded
ACPI: Unable to derive IRQ for device 0000:00:10.0
ACPI: PCI Interrupt 0000:00:10.0[A]: no GSI
scsi0 : pata_ali
scsi1 : pata_ali
ata1: PATA max UDMA/133 cmd 0x000101f0 ctl 0x000103f6 bmdma 0x00018080 irq 14
ata2: PATA max UDMA/133 cmd 0x00010170 ctl 0x00010376 bmdma 0x00018088 irq 15
ata1.00: ATA-6: ST9100823A, 3.00, max UDMA/100
ata1.00: 195371568 sectors, multi 16: LBA
ata1.00: configured for UDMA/100
ata2.00: ATAPI: DW-224E, A.0H, max MWDMA2
ata2.00: configured for MWDMA2
scsi 0:0:0:0: Direct-Access     ATA      ST9100823A       3.00 PQ: 0 ANSI: 5
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
ata2.00: cmd a0/01:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x12 data 96 in
         res 40/00:02:00:24:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for MWDMA2
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
ata2.00: cmd a0/01:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x12 data 96 in
         res 40/00:02:00:24:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for MWDMA2
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
ata2.00: cmd a0/01:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x12 data 96 in
         res 40/00:02:00:24:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for MWDMA2
ata2: EH complete
ata2.00: limiting speed to MWDMA1:PIO4
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
ata2.00: cmd a0/01:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x12 data 96 in
         res 40/00:02:00:24:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for MWDMA1
ata2: EH complete
scsi scan: 96 byte inquiry failed.  Consider BLIST_INQUIRY_36 for this device
scsi 1:0:0:0: CD-ROM            TEAC     DW-224E          A.0H PQ: 0 ANSI: 5
ohci_hcd: 2006 August 04 USB 1.1 'Open' Host Controller (OHCI) Driver
ACPI: PCI Interrupt Link [LNKU] enabled at IRQ 10
ACPI: PCI Interrupt 0000:00:02.0[A] -> Link [LNKU] -> GSI 10 (level, low) -> IRQ 10
ohci_hcd 0000:00:02.0: OHCI Host Controller
ohci_hcd 0000:00:02.0: new USB bus registered, assigned bus number 1
ohci_hcd 0000:00:02.0: irq 10, io mem 0xd0006000
usb usb1: configuration #1 chosen from 1 choice
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 4 ports detected
USB Universal Host Controller Interface driver v3.0
sl811: driver sl811-hcd, 19 May 2005
PNP: PS/2 Controller [PNP0303:KBC0,PNP0f13:MSE0] at 0x60,0x64 irq 1,12
serio: i8042 KBD port at 0x60,0x64 irq 1
serio: i8042 AUX port at 0x60,0x64 irq 12
mice: PS/2 mouse device common for all mice
input: AT Translated Set 2 keyboard as /class/input/input0
device-mapper: ioctl: 4.11.0-ioctl (2006-10-12) initialised: dm-devel@redhat.com
usb 1-1: new full speed USB device using ohci_hcd and address 2
usb 1-1: configuration #1 chosen from 1 choice
hub 1-1:1.0: USB hub found
hub 1-1:1.0: 3 ports detected
Synaptics Touchpad, model: 1, fw: 5.8, id: 0x2348b3, caps: 0x904713/0x10008
input: SynPS/2 Synaptics TouchPad as /class/input/input1
usb 1-1.1: new low speed USB device using ohci_hcd and address 3
usb 1-1.1: configuration #1 chosen from 1 choice
usb 1-1.2: new low speed USB device using ohci_hcd and address 4
usb 1-1.2: configuration #1 chosen from 1 choice
usb 1-1.3: new full speed USB device using ohci_hcd and address 5
usb 1-1.3: configuration #1 chosen from 1 choice
input: Logitech USB Trackball as /class/input/input2
input: USB HID v1.10 Mouse [Logitech USB Trackball] on usb-0000:00:02.0-1.1
input: Logitech Trackball as /class/input/input3
input: USB HID v1.10 Mouse [Logitech Trackball] on usb-0000:00:02.0-1.2
input: ORTEK USB Keyboard Hub as /class/input/input4
input: USB HID v1.10 Keyboard [ORTEK USB Keyboard Hub] on usb-0000:00:02.0-1.3
input: ORTEK USB Keyboard Hub as /class/input/input5
input: USB HID v1.10 Device [ORTEK USB Keyboard Hub] on usb-0000:00:02.0-1.3
usbcore: registered new interface driver usbhid
/usr/src/shared/linux-2.6.22/drivers/hid/usbhid/hid-core.c: v2.6:USB HID core driver
TCP cubic registered
NET: Registered protocol family 1
NET: Registered protocol family 17
Using IPI Shortcut mode
Freeing unused kernel memory: 20872k freed
scsi 0:0:0:0: Attached scsi generic sg0 type 0
scsi 1:0:0:0: Attached scsi generic sg1 type 5
agpgart: Detected Ati IGP320/M chipset
agpgart: AGP aperture is 64M @ 0xd4000000
Yenta: CardBus bridge found at 0000:00:0a.0 [103c:0024]
Yenta O2: res at 0x94/0xD4: 00/ea
Yenta O2: enabling read prefetch/write burst
natsemi dp8381x driver, version 2.1, Sept 11, 2006
  originally by Donald Becker <becker@scyld.com>
  2.4.x kernel port by Jeff Garzik, Tjeerd Mulder
sd 0:0:0:0: [sda] 195371568 512-byte hardware sectors (100030 MB)
sd 0:0:0:0: [sda] Write Protect is off
sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sd 0:0:0:0: [sda] 195371568 512-byte hardware sectors (100030 MB)
sd 0:0:0:0: [sda] Write Protect is off
sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
 sda:<6>Yenta: ISA IRQ mask 0x00b8, PCI irq 11
Socket status: 30000007
ACPI: PCI Interrupt Link [LNKB] enabled at IRQ 11
ACPI: PCI Interrupt 0000:00:12.0[A] -> Link [LNKB] -> GSI 11 (level, low) -> IRQ 11
natsemi eth0: NatSemi DP8381[56] at 0xd000a000 (0000:00:12.0), 00:0d:9d:81:e8:17, IRQ 11, port TP.
 sda1 sda2 sda3 sda4 <<6>parport_pc 00:09: reported by Plug and Play ACPI
parport0: PC-style at 0x378 (0x778), irq 7, dma 0 [PCSPP,TRISTATE,COMPAT,ECP,DMA]
ACPI: PCI Interrupt Link [LNKH] enabled at IRQ 5
PCI: setting IRQ 5 as level-triggered
ACPI: PCI Interrupt 0000:00:06.0[A] -> Link [LNKH] -> GSI 5 (level, low) -> IRQ 5
 sda5 sda6 sda7 >
sd 0:0:0:0: [sda] Attached SCSI disk
AC'97 1 does not respond - RESET
AC'97 1 access is not valid [0xffffffff], removing mixer.
ali mixer 1 creating error.
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
ata2.00: cmd a0/01:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x5a data 128 in
         res 40/00:03:00:00:20/00:00:00:00:00/a0 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for MWDMA1
ata2: EH complete
ndiswrapper version 1.47 loaded (smp=no)
ndiswrapper: driver bcmwl5a (Broadcom,06/26/2004, 3.70.17.0) loaded
ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 10
ACPI: PCI Interrupt 0000:00:09.0[A] -> Link [LNKD] -> GSI 10 (level, low) -> IRQ 10
ndiswrapper: using IRQ 10
wlan0: ethernet device 00:90:4b:41:56:90 using NDIS driver: bcmwl5a, version: 0x3461100, NDIS version: 0x501, vendor: 'NDIS Network Adapter', 14E4:4320.5.conf
wlan0: encryption modes supported: WEP; TKIP with WPA; AES/CCMP with WPA
usbcore: registered new interface driver ndiswrapper
ndiswrapper: changing interface name from 'wlan0' to 'eth1'
unionfs: error accessing lower directory '/var/lib/initramfs/etc' (error -2)
unionfs: read_super: error while parsing options (err = -2)
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
ata2.00: cmd a0/01:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x5a data 128 in
         res 40/00:03:00:00:20/00:00:00:00:00/a0 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for MWDMA1
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
ata2.00: cmd a0/01:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x5a data 128 in
         res 40/00:03:00:00:20/00:00:00:00:00/a0 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for MWDMA1
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
ata2.00: cmd a0/01:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x5a data 128 in
         res 40/00:03:00:00:20/00:00:00:00:00/a0 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for MWDMA1
ata2: EH complete
sr0: scsi-1 drive
Uniform CD-ROM driver Revision: 3.20
sr 1:0:0:0: Attached scsi CD-ROM sr0
Comment 9 Tejun Heo 2007-08-08 20:26:42 UTC
* please test 2.6.22.1
* if that fails too, please test 2.6.22.1 + the following patch.
Comment 10 Tejun Heo 2007-08-08 20:27:13 UTC
Created attachment 12325 [details]
force-pio-on-dw224e.patch
Comment 11 Jack Byer 2007-08-09 18:16:48 UTC
2.6.22.1 (unpatched) works... intermittently

The first time I tried it, the system booted correctly. At this point I remembered I forget to build the network driver. (kernel sources are located on an NFS share).

I rebooted into the old kernel, and built my network driver. Ever since that first successful boot no subsequent tries have been successful. Just to be sure, I'm doing a clean rebuild of the kernel then I am going to power cycle the machine, to see if that makes a difference.
Comment 12 Jack Byer 2007-08-09 19:14:11 UTC
I found the (one?) problem. The sr_mod module was hanging the boot scripts and somehow the sda* device files weren't getting created by udev. When I remove the sr_mod.ko module everything boots just fine. Here's the new dmesg:

Linux version 2.6.22.1-cfs-v19 (root@lithium) (gcc version 4.1.2 (Gentoo 4.1.2)) #17 PREEMPT Thu Aug 9 20:59:59 CDT 2007
BIOS-provided physical RAM map:
 BIOS-e820: 0000000000000000 - 000000000009f800 (usable)
 BIOS-e820: 000000000009f800 - 00000000000a0000 (reserved)
 BIOS-e820: 00000000000d0000 - 0000000000100000 (reserved)
 BIOS-e820: 0000000000100000 - 000000003bef0000 (usable)
 BIOS-e820: 000000003bef0000 - 000000003beff000 (ACPI data)
 BIOS-e820: 000000003beff000 - 000000003bf00000 (ACPI NVS)
 BIOS-e820: 000000003bf00000 - 000000003c000000 (reserved)
 BIOS-e820: 00000000fffc0000 - 0000000100000000 (reserved)
62MB HIGHMEM available.
896MB LOWMEM available.
Entering add_active_range(0, 0, 245488) 0 entries of 256 used
Zone PFN ranges:
  DMA             0 ->     4096
  Normal       4096 ->   229376
  HighMem    229376 ->   245488
early_node_map[1] active PFN ranges
    0:        0 ->   245488
On node 0 totalpages: 245488
  DMA zone: 32 pages used for memmap
  DMA zone: 0 pages reserved
  DMA zone: 4064 pages, LIFO batch:0
  Normal zone: 1760 pages used for memmap
  Normal zone: 223520 pages, LIFO batch:31
  HighMem zone: 125 pages used for memmap
  HighMem zone: 15987 pages, LIFO batch:3
DMI 2.3 present.
ACPI: RSDP 000F72B0, 0014 (r0 PTLTD )
ACPI: RSDT 3BEF8CCA, 0030 (r1 PTLTD    RSDT    6040000  LTP        0)
ACPI: FACP 3BEFEE2B, 0074 (r1 ATI    Raptor    6040000 ATI     F4240)
ACPI: DSDT 3BEF8CFA, 6131 (r1    ATI U1_M1535  6040000 MSFT  100000D)
ACPI: FACS 3BEFFFC0, 0040
ACPI: BOOT 3BEFEE9F, 0028 (r1 PTLTD  $SBFTBL$  6040000  LTP        1)
ACPI: SSDT 3BEFEEC7, 0139 (r1 PTLTD  POWERNOW  6040000  LTP        1)
ATI board detected. Disabling timer routing over 8254.
ACPI: PM-Timer IO Port: 0x8008
Allocating PCI resources starting at 40000000 (gap: 3c000000:c3fc0000)
Built 1 zonelists.  Total pages: 243571
Kernel command line: video=radeonfb:1024x768-32@80
Local APIC disabled by BIOS -- you can enable it with "lapic"
mapped APIC to ffffd000 (020ee000)
Enabling fast FPU save and restore... done.
Enabling unmasked SIMD FPU exception support... done.
Initializing CPU#0
PID hash table entries: 4096 (order: 12, 16384 bytes)
Detected 1788.999 MHz processor.
Console: colour VGA+ 80x25
Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
Memory: 943848k/981952k available (3008k kernel code, 37576k reserved, 812k data, 20912k init, 64448k highmem)
virtual kernel memory layout:
    fixmap  : 0xfffaa000 - 0xfffff000   ( 340 kB)
    pkmap   : 0xff800000 - 0xffc00000   (4096 kB)
    vmalloc : 0xf8800000 - 0xff7fe000   ( 111 MB)
    lowmem  : 0xc0000000 - 0xf8000000   ( 896 MB)
      .init : 0xc04be000 - 0xc192a000   (20912 kB)
      .data : 0xc03f0347 - 0xc04bb3dc   ( 812 kB)
      .text : 0xc0100000 - 0xc03f0347   (3008 kB)
Checking if this processor honours the WP bit even in supervisor mode... Ok.
Calibrating delay using timer specific routine.. 3578.55 BogoMIPS (lpj=1789275)
Mount-cache hash table entries: 512
CPU: After generic identify, caps: 0383f9ff c1cbf9ff 00000000 00000000 00000000 00000000 00000000
CPU: L1 I Cache: 64K (64 bytes/line), D cache 64K (64 bytes/line)
CPU: L2 Cache: 512K (64 bytes/line)
CPU: After all inits, caps: 0383f9ff c1cbf9ff 00000000 00000420 00000000 00000000 00000000
Intel machine check architecture supported.
Intel machine check reporting enabled on CPU#0.
Compat vDSO mapped to ffffe000.
CPU: AMD mobile AMD Athlon(tm) XP2400+ stepping 00
Checking 'hlt' instruction... OK.
ACPI: Core revision 20070126
ACPI: setting ELCR to 0200 (from 0e28)
NET: Registered protocol family 16
ACPI: bus type pci registered
PCI: PCI BIOS revision 2.10 entry at 0xfd87b, last bus=2
PCI: Using configuration type 1
Setting up standard PCI resources
ACPI: Interpreter enabled
ACPI: (supports S0 S3 S4 S5)
ACPI: Using PIC for interrupt routing
ACPI: PCI Root Bridge [PCI0] (0000:00)
PCI: Probing PCI hardware (bus 00)
PCI quirk: region 8000-803f claimed by ali7101 ACPI
PCI quirk: region 8040-805f claimed by ali7101 SMB
ACPI: PCI Interrupt Routing Table [\_SB_.PCI0._PRT]
ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.AGPB._PRT]
ACPI: PCI Interrupt Link [LNKA] (IRQs 3 4 6 *10)
ACPI: PCI Interrupt Link [LNKB] (IRQs 7 *11)
ACPI: PCI Interrupt Link [LNKC] (IRQs 3 4 6 10) *9
ACPI: PCI Interrupt Link [LNKD] (IRQs 3 4 6 *10)
ACPI: PCI Interrupt Link [LNKE] (IRQs 3 4 6 10) *0, disabled.
ACPI: PCI Interrupt Link [LNKF] (IRQs 7 *11)
ACPI: PCI Interrupt Link [LNKG] (IRQs *3 4 6 10)
ACPI: PCI Interrupt Link [LNKH] (IRQs *5 7)
ACPI: PCI Interrupt Link [LNKU] (IRQs 3 4 6 10) *9
Linux Plug and Play Support v0.97 (c) Adam Belay
pnp: PnP ACPI init
ACPI: bus type pnp registered
pnp: PnP ACPI: found 11 devices
ACPI: ACPI bus type pnp unregistered
SCSI subsystem initialized
libata version 2.21 loaded.
usbcore: registered new interface driver usbfs
usbcore: registered new interface driver hub
usbcore: registered new device driver usb
PCI: Using ACPI for IRQ routing
PCI: If a device doesn't work, try "pci=routeirq".  If it helps, post a report
pnp: 00:07: ioport range 0x40b-0x40b has been reserved
pnp: 00:07: ioport range 0x480-0x48f has been reserved
pnp: 00:07: ioport range 0x4d0-0x4d1 has been reserved
pnp: 00:07: ioport range 0x4d6-0x4d6 has been reserved
pnp: 00:07: ioport range 0x8000-0x807f could not be reserved
pnp: 00:07: iomem range 0xe0500000-0xe0500fff has been reserved
Time: tsc clocksource has been installed.
pnp: 00:07: iomem range 0xd0500000-0xd0500fff has been reserved
PCI: Bridge: 0000:00:01.0
  IO window: 9000-9fff
  MEM window: d0100000-d01fffff
  PREFETCH window: e0000000-efffffff
PCI: Bus 2, cardbus bridge: 0000:00:0a.0
  IO window: 00001000-000010ff
  IO window: 00001400-000014ff
  PREFETCH window: 40000000-43ffffff
  MEM window: 44000000-47ffffff
ACPI: PCI Interrupt Link [LNKF] enabled at IRQ 11
PCI: setting IRQ 11 as level-triggered
ACPI: PCI Interrupt 0000:00:0a.0[A] -> Link [LNKF] -> GSI 11 (level, low) -> IRQ 11
NET: Registered protocol family 2
IP route cache hash table entries: 32768 (order: 5, 131072 bytes)
TCP established hash table entries: 131072 (order: 8, 1048576 bytes)
TCP bind hash table entries: 65536 (order: 6, 262144 bytes)
TCP: Hash tables configured (established 131072 bind 65536)
TCP reno registered
Switched to high resolution mode on CPU 0
Simple Boot Flag at 0x36 set to 0x1
Machine check exception polling timer started.
highmem bounce pool size: 64 pages
Total HugeTLB memory allocated, 0
SGI XFS with ACLs, security attributes, realtime, large block numbers, no debug enabled
SGI XFS Quota Management subsystem
io scheduler noop registered
io scheduler cfq registered (default)
ATI Northbridge, reserving I/O ports 0x3b0 to 0x3bb.
Activating ISA DMA hang workarounds.
Boot video device is 0000:01:05.0
ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 10
PCI: setting IRQ 10 as level-triggered
ACPI: PCI Interrupt 0000:01:05.0[A] -> Link [LNKC] -> GSI 10 (level, low) -> IRQ 10
PCI: Unable to reserve mem region #1:10000000@e0000000 for device 0000:01:05.0
radeonfb (0000:01:05.0): cannot request region 0.
radeonfb: probe of 0000:01:05.0 failed with error -16
Real Time Clock Driver v1.12ac
Linux agpgart interface v0.102 (c) Dave Jones
Hangcheck: starting hangcheck timer 0.9.0 (tick is 180 seconds, margin is 60 seconds).
Hangcheck: Using get_cycles().
Serial: 8250/16550 driver $Revision: 1.90 $ 4 ports, IRQ sharing disabled
00:0a: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
ACPI: PCI Interrupt Link [LNKG] enabled at IRQ 3
PCI: setting IRQ 3 as level-triggered
ACPI: PCI Interrupt 0000:00:08.0[A] -> Link [LNKG] -> GSI 3 (level, low) -> IRQ 3
0000:00:08.0: ttyS1 at I/O 0x8828 (irq = 3) is a 8250
0000:00:08.0: ttyS2 at I/O 0x8840 (irq = 3) is a 8250
0000:00:08.0: ttyS3 at I/O 0x8850 (irq = 3) is a 8250
Couldn't register serial port 0000:00:08.0: -28
RAMDISK driver initialized: 16 RAM disks of 4096K size 1024 blocksize
loop: module loaded
ACPI: Unable to derive IRQ for device 0000:00:10.0
ACPI: PCI Interrupt 0000:00:10.0[A]: no GSI
scsi0 : pata_ali
scsi1 : pata_ali
ata1: PATA max UDMA/100 cmd 0x000101f0 ctl 0x000103f6 bmdma 0x00018080 irq 14
ata2: PATA max UDMA/100 cmd 0x00010170 ctl 0x00010376 bmdma 0x00018088 irq 15
ata1.00: ATA-6: ST9100823A, 3.00, max UDMA/100
ata1.00: 195371568 sectors, multi 16: LBA
ata1.00: configured for UDMA/100
ata2.00: ATAPI: DW-224E, A.0H, max MWDMA2
ata2.00: configured for MWDMA2
scsi 0:0:0:0: Direct-Access     ATA      ST9100823A       3.00 PQ: 0 ANSI: 5
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
ata2.00: cmd a0/01:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x12 data 96 in
         res 40/00:02:00:24:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for MWDMA2
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
ata2.00: cmd a0/01:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x12 data 96 in
         res 40/00:02:00:24:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for MWDMA2
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
ata2.00: cmd a0/01:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x12 data 96 in
         res 40/00:02:00:24:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for MWDMA2
ata2: EH complete
ata2.00: limiting speed to MWDMA1:PIO4
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
ata2.00: cmd a0/01:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x12 data 96 in
         res 40/00:02:00:24:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for MWDMA1
ata2: EH complete
scsi scan: 96 byte inquiry failed.  Consider BLIST_INQUIRY_36 for this device
scsi 1:0:0:0: CD-ROM            TEAC     DW-224E          A.0H PQ: 0 ANSI: 5
ohci_hcd: 2006 August 04 USB 1.1 'Open' Host Controller (OHCI) Driver
ACPI: PCI Interrupt Link [LNKU] enabled at IRQ 10
ACPI: PCI Interrupt 0000:00:02.0[A] -> Link [LNKU] -> GSI 10 (level, low) -> IRQ 10
ohci_hcd 0000:00:02.0: OHCI Host Controller
ohci_hcd 0000:00:02.0: new USB bus registered, assigned bus number 1
ohci_hcd 0000:00:02.0: irq 10, io mem 0xd0006000
usb usb1: configuration #1 chosen from 1 choice
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 4 ports detected
USB Universal Host Controller Interface driver v3.0
sl811: driver sl811-hcd, 19 May 2005
PNP: PS/2 Controller [PNP0303:KBC0,PNP0f13:MSE0] at 0x60,0x64 irq 1,12
serio: i8042 KBD port at 0x60,0x64 irq 1
serio: i8042 AUX port at 0x60,0x64 irq 12
mice: PS/2 mouse device common for all mice
device-mapper: ioctl: 4.11.0-ioctl (2006-10-12) initialised: dm-devel@redhat.com
input: AT Translated Set 2 keyboard as /class/input/input0
usb 1-1: new full speed USB device using ohci_hcd and address 2
usb 1-1: configuration #1 chosen from 1 choice
hub 1-1:1.0: USB hub found
hub 1-1:1.0: 3 ports detected
usb 1-1.1: new low speed USB device using ohci_hcd and address 3
usb 1-1.1: configuration #1 chosen from 1 choice
usb 1-1.2: new low speed USB device using ohci_hcd and address 4
usb 1-1.2: configuration #1 chosen from 1 choice
usb 1-1.3: new full speed USB device using ohci_hcd and address 5
usb 1-1.3: configuration #1 chosen from 1 choice
input: Logitech USB Trackball as /class/input/input1
input: USB HID v1.10 Mouse [Logitech USB Trackball] on usb-0000:00:02.0-1.1
input: Logitech Trackball as /class/input/input2
input: USB HID v1.10 Mouse [Logitech Trackball] on usb-0000:00:02.0-1.2
input: ORTEK USB Keyboard Hub as /class/input/input3
input: USB HID v1.10 Keyboard [ORTEK USB Keyboard Hub] on usb-0000:00:02.0-1.3
input: ORTEK USB Keyboard Hub as /class/input/input4
input: USB HID v1.10 Device [ORTEK USB Keyboard Hub] on usb-0000:00:02.0-1.3
usbcore: registered new interface driver usbhid
/usr/src/shared/linux-2.6.22/drivers/hid/usbhid/hid-core.c: v2.6:USB HID core driver
TCP cubic registered
NET: Registered protocol family 1
NET: Registered protocol family 17
Using IPI Shortcut mode
Freeing unused kernel memory: 20912k freed
scsi 0:0:0:0: Attached scsi generic sg0 type 0
scsi 1:0:0:0: Attached scsi generic sg1 type 5
agpgart: Detected Ati IGP320/M chipset
agpgart: AGP aperture is 64M @ 0xd4000000
sd 0:0:0:0: [sda] 195371568 512-byte hardware sectors (100030 MB)
sd 0:0:0:0: [sda] Write Protect is off
sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sd 0:0:0:0: [sda] 195371568 512-byte hardware sectors (100030 MB)
sd 0:0:0:0: [sda] Write Protect is off
sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
 sda:<6>natsemi dp8381x driver, version 2.1, Sept 11, 2006
  originally by Donald Becker <becker@scyld.com>
  2.4.x kernel port by Jeff Garzik, Tjeerd Mulder
ACPI: PCI Interrupt Link [LNKB] enabled at IRQ 11
ACPI: PCI Interrupt 0000:00:12.0[A] -> Link [LNKB] -> GSI 11 (level, low) -> IRQ 11
 sda1 sda2 sda3 sda4 <<6>natsemi eth0: NatSemi DP8381[56] at 0xd000a000 (0000:00:12.0), 00:0d:9d:81:e8:17, IRQ 11, port TP.
Yenta: CardBus bridge found at 0000:00:0a.0 [103c:0024]
Yenta O2: res at 0x94/0xD4: 00/ea
Yenta O2: enabling read prefetch/write burst
 sda5 sda6<6>Yenta: ISA IRQ mask 0x00b8, PCI irq 11
Socket status: 30000007
ACPI: PCI Interrupt Link [LNKH] enabled at IRQ 5
PCI: setting IRQ 5 as level-triggered
ACPI: PCI Interrupt 0000:00:06.0[A] -> Link [LNKH] -> GSI 5 (level, low) -> IRQ 5
 sda7 >
sd 0:0:0:0: [sda] Attached SCSI disk
parport_pc 00:09: reported by Plug and Play ACPI
parport0: PC-style at 0x378 (0x778), irq 7, dma 0 [PCSPP,TRISTATE,COMPAT,ECP,DMA]
AC'97 1 does not respond - RESET
AC'97 1 access is not valid [0xffffffff], removing mixer.
ali mixer 1 creating error.
ndiswrapper version 1.47 loaded (smp=no)
ndiswrapper: driver bcmwl5a (Broadcom,06/26/2004, 3.70.17.0) loaded
ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 10
ACPI: PCI Interrupt 0000:00:09.0[A] -> Link [LNKD] -> GSI 10 (level, low) -> IRQ 10
ndiswrapper: using IRQ 10
wlan0: ethernet device 00:90:4b:41:56:90 using NDIS driver: bcmwl5a, version: 0x3461100, NDIS version: 0x501, vendor: 'NDIS Network Adapter', 14E4:4320.5.conf
wlan0: encryption modes supported: WEP; TKIP with WPA; AES/CCMP with WPA
usbcore: registered new interface driver ndiswrapper
ndiswrapper: changing interface name from 'wlan0' to 'eth1'
XFS mounting filesystem sda3
Ending clean XFS mount for filesystem: sda3
XFS mounting filesystem sda5
Ending clean XFS mount for filesystem: sda5
XFS mounting filesystem sda6
Ending clean XFS mount for filesystem: sda6
Adding 2000368k swap on /dev/mapper/crypt-swap.  Priority:-1 extents:1 across:2000368k
[drm] Initialized drm 1.1.0 20060810
[drm] Initialized radeon 1.27.0 20060524 on minor 0
agpgart: Found an AGP 2.0 compliant device at 0000:00:00.0.
agpgart: Putting AGP V2 device at 0000:00:00.0 into 4x mode
agpgart: Putting AGP V2 device at 0000:01:05.0 into 4x mode
[drm] Setting GART location based on old memory map
[drm] writeback test succeeded in 1 usecs
Comment 13 Tejun Heo 2007-08-09 23:12:28 UTC
Can you give a shot at the patch?  Thanks.
Comment 14 Jack Byer 2007-08-10 16:37:37 UTC
The patch works perfectly (also upgraded to 2.6.22.2)

sd 0:0:0:0: [sda] 195371568 512-byte hardware sectors (100030 MB)
sd 0:0:0:0: [sda] Write Protect is off
sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sd 0:0:0:0: [sda] 195371568 512-byte hardware sectors (100030 MB)
sd 0:0:0:0: [sda] Write Protect is off
sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
 sda:<6>natsemi eth0: NatSemi DP8381[56] at 0xd000a000 (0000:00:12.0), 00:0d:9d:81:e8:17, IRQ 11, port TP.
 sda1 sda2 sda3 sda4 <sr0: scsi3-mmc drive: 24x/24x writer cd/rw xa/form2 cdda tray
Uniform CD-ROM driver Revision: 3.20
sr 1:0:0:0: Attached scsi CD-ROM sr0
 sda5 sda6 sda7 >
sd 0:0:0:0: [sda] Attached SCSI disk
Comment 15 Tejun Heo 2007-08-10 20:52:43 UTC
Do you happen to have another sata controller?  We have several reports of MWDMA failures on pata_ali and aren't really sure whether it's the problem of the controller or the attached devices.  If you have another sata controller, please connect dw224e to the controller and boot without the patch applied and report the result.  Thanks.
Comment 16 Jack Byer 2007-08-11 05:11:33 UTC
Which component is the dw224e? I know that the hard drive and the cd-rom drive are removable, but I've never looked at them to see if they use the same standard connector as desktop systems. Also, this laptop does not have an SATA controller, it has an IDE controller.
Comment 17 Andrey Borzenkov 2007-08-13 10:18:15 UTC
I have the same problem with TOSHIBA DVD-ROM SD-C2502, ATAPI CD/DVD-ROM drive. Turning off DMA on ATAPI is hardly an option (it kills DVD watching as example).

It is unlikely to be device-specific. There are more reports, see

http://lkml.org/lkml/2006/6/20/309
http://www.opensubscriber.com/message/linux-ide%40vger.kernel.org/7326463.html
http://lkml.org/lkml/2007/8/11/53

Last version I tested was 2.6.22 then I needed DVD and switched to legacy IDE. But I can easily rebuild initrd with pata_ali.
Comment 18 Tejun Heo 2007-08-13 18:40:09 UTC
Andrey, so the IDE driver alim15x3 works fine while pata_ali doesn't?
Comment 19 Andrey Borzenkov 2007-08-13 19:22:32 UTC
(In reply to comment #18)
> Andrey, so the IDE driver alim15x3 works fine while pata_ali doesn't?
> 

Exactly. Here is booting with IDE:

[ 4715.100554] ALI15X3: IDE controller at PCI slot 0000:00:04.0
[ 4715.127236] ACPI: Unable to derive IRQ for device 0000:00:04.0
[ 4715.153395] ACPI: PCI Interrupt 0000:00:04.0[A]: no GSI
[ 4715.179366] ALI15X3: chipset revision 195
[ 4715.204982] ALI15X3: not 100% native mode: will probe irqs later
[ 4715.230863]     ide0: BM-DMA at 0xeff0-0xeff7, BIOS settings: hda:DMA, hdb:pio
[ 4715.257254]     ide1: BM-DMA at 0xeff8-0xefff, BIOS settings: hdc:DMA, hdd:pio
[ 4715.283298] Probing IDE interface ide0...
[ 4715.557602] hda: IC25N020ATDA04-0, ATA DISK drive
[ 4716.220582] hda: host side 80-wire cable detection failed, limiting max speed to UDMA33
[ 4716.247130] hda: selected mode 0x42
[ 4716.247621] ide0 at 0x1f0-0x1f7,0x3f6 on irq 14
[ 4716.290829] Probing IDE interface ide1...
[ 4716.990605] hdc: TOSHIBA DVD-ROM SD-C2502, ATAPI CD/DVD-ROM drive
[ 4717.656913] hdc: selected mode 0x42
...
Comment 20 Tejun Heo 2007-08-13 19:35:06 UTC
Please post the results of 'lspci -nnvvvxxx' when booted from pata_ali and alim15x3.  Thanks.

Alan, this looks like a mode programming problem.
Comment 21 Albert Lee 2007-08-13 21:36:42 UTC
> ... this looks like a mode programming problem.

Yes, it's possibly the problem of mwdma2 mode programming. But there is also another possibility that ALi not working with INQUIRY + DMA.

I am curious how the old IDE ALi driver work with INQUIRY + DMA.

Andrey, could you please try boot with IDE and collect the result of
1. 'hdparm -I /dev/hdc' and
2. 'cdrecord -v -V -inq dev=/dev/hdc'
Thanks.
Comment 22 Andrey Borzenkov 2007-08-14 11:31:42 UTC
Created attachment 12385 [details]
dmesg, lspci, hdparm and cdrecord for pata and ide

Attached is ali.zip that contains requested output for both pata and ide. To me suspiciously looking are register 0x58 and 0x5c (primary and secondary address setup timing registers); they are 2 clocks for IDE and 1 clock for PATA. IDE ali driver computes them directly; pata one takes them from libata and just makes sure they fit in bounds.

But this of course may be red herring.
Comment 23 Alan 2007-08-14 16:12:03 UTC
Easy enough to add 1 to it and test. Just bump them in pata_ali.c boot the result and see. One huge advantage you have with this bug is you've got hardware that breaks
Comment 24 Andrey Borzenkov 2007-08-15 10:30:42 UTC
well, here is diff between lspci with IDE and modified pata_ali (it was more than just this register); second hunk is 5229; line number refer to lspci I have attached earlier. As you see, IDE and PATA case are identical except for UDMA33 vs UDMA25. God knows why setup of Northbridge (M1644/M1644T) - first hunk - and Cardbus - third hunk - depends on IDE vs. PATA. The problem is still there - nothing has changed. I am ready to test patches but I hit my limits to fix it myself.

--- ide/lspci.out       2007-08-14 21:49:40.000000000 +0400
+++ pata.timings/lspci.out      2007-08-15 21:04:43.000000000 +0400
@@ -20,18 +20,17 @@
 80: 00 00 53 b7 31 88 20 f0 20 02 00 00 00 00 78 00
 90: 15 00 d5 49 00 00 00 00 08 00 00 00 f8 ae 00 00
 a0: 34 ee 01 00 01 00 01 00 00 00 00 00 00 00 00 00
-b0: 02 a4 20 00 07 02 00 1b 00 00 00 00 08 00 a7 1d
+b0: 02 a4 20 00 07 02 00 1b 00 00 00 00 08 00 97 1d
 c0: 10 00 13 10 00 00 00 f0 c0 68 00 c0 00 00 00 00
 d0: 67 c0 40 cf 00 b0 65 1e 00 00 00 80 81 81 89 00
 e0: 00 60 20 00 00 00 b8 40 00 00 08 00 00 00 28 31
-f0: 00 00 00 3c 80 07 80 07 00 00 00 00 00 00 00 00
+f0: 00 80 00 3c 80 07 80 07 00 00 00 00 00 00 00 00

 00:01.0 PCI bridge [0604]: ALi Corporation PCI to AGP Controller [10b9:5247] (prog-if 00 [Normal decode])
        Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B-
        Status: Cap- 66MHz- UDF- FastB2B- ParErr- DEVSEL=slow >TAbort- <TAbort- <MAbort- >SERR- <PERR-
        Latency: 0
        Bus: primary=00, secondary=01, subordinate=01, sec-latency=0
-       I/O behind bridge: 0000f000-00000fff
        Memory behind bridge: f7f00000-fdffffff
        Prefetchable memory behind bridge: 48000000-480fffff
        Secondary status: 66MHz+ FastB2B- ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort+ <SERR- <PERR+
@@ -99,7 +98,7 @@ f0: 00 00 00 00 00 00 00 00 00 00 00 00
 20: f1 ef 00 00 00 00 00 00 00 00 00 00 79 11 04 00
 30: 00 00 00 00 60 00 00 00 00 00 00 00 ff 01 02 04
 40: 06 00 00 7f 00 00 00 00 00 02 23 c9 00 80 ba 1a
-50: 03 00 00 89 01 01 0a 0a 02 31 31 00 02 31 31 00
+50: 03 00 00 89 01 01 0a 0b 02 31 31 00 02 31 31 00
 60: 01 00 02 00 00 00 00 00 00 00 00 00 00 00 00 00
 70: 00 00 00 00 00 00 00 00 21 00 00 00 00 00 00 00
 80: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
@@ -236,7 +235,7 @@ f0: 00 00 00 00 00 00 00 00 00 00 00 00
 50: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 60: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 70: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
-80: 60 d0 44 00 00 00 00 00 00 00 00 00 02 00 00 01
+80: 60 f0 44 00 00 00 00 00 00 00 00 00 02 00 00 01
 90: c0 01 60 61 00 00 00 00 00 00 00 00 00 00 00 00
 a0: 01 00 11 fe 00 00 c0 00 0f 08 00 00 1b 00 00 00
 b0: 00 00 00 08 00 00 00 00 00 00 00 00 00 00 00 00
Comment 25 Andrey Borzenkov 2007-10-26 10:24:43 UTC
Status update for 2.6.24-rc1.

pata_ali now manages to find DVD-ROM after error recovery but it is still unusable because *every* access results in lengthy error recovery (even booting in run level 1 I have to wait about 2 munutes for udev to finish device scanning). Here is dmesg from 2.6.24-rc1 with pata_ali:

[    0.000000] Linux version 2.6.24-rc1-2avb (bor@cooker) (gcc version 4.2.2 20070909 (prerelease) (4.2.2-0.RC.1mdv2008.0)) #2 Fri Oct 26 19:59:00 MSD 2007
[    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: 00000000000e0000 - 00000000000eee00 (reserved)
[    0.000000]  BIOS-e820: 00000000000eee00 - 00000000000ef000 (ACPI NVS)
[    0.000000]  BIOS-e820: 00000000000ef000 - 0000000000100000 (reserved)
[    0.000000]  BIOS-e820: 0000000000100000 - 000000001ef60000 (usable)
[    0.000000]  BIOS-e820: 000000001ef60000 - 000000001ef70000 (ACPI data)
[    0.000000]  BIOS-e820: 000000001ef70000 - 0000000020000000 (reserved)
[    0.000000]  BIOS-e820: 00000000fff80000 - 0000000100000000 (reserved)
[    0.000000] 495MB LOWMEM available.
[    0.000000] Entering add_active_range(0, 0, 126816) 0 entries of 256 used
[    0.000000] Zone PFN ranges:
[    0.000000]   DMA             0 ->     4096
[    0.000000]   Normal       4096 ->   126816
[    0.000000] Movable zone start PFN for each node
[    0.000000] early_node_map[1] active PFN ranges
[    0.000000]     0:        0 ->   126816
[    0.000000] On node 0 totalpages: 126816
[    0.000000]   DMA zone: 32 pages used for memmap
[    0.000000]   DMA zone: 0 pages reserved
[    0.000000]   DMA zone: 4064 pages, LIFO batch:0
[    0.000000]   Normal zone: 958 pages used for memmap
[    0.000000]   Normal zone: 121762 pages, LIFO batch:31
[    0.000000]   Movable zone: 0 pages used for memmap
[    0.000000] DMI 2.3 present.
[    0.000000] ACPI: RSDP 000F0090, 0014 (r0 TOSHIB)
[    0.000000] ACPI: RSDT 1EF60000, 0028 (r1 TOSHIB 750        970814 TASM  4010000)
[    0.000000] ACPI: FACP 1EF60054, 0084 (r2 TOSHIB 750        970814 TASM  4010000)
[    0.000000] ACPI: DSDT 1EF600D8, 68DA (r1 TOSHIB 4000     20020417 MSFT  100000A)
[    0.000000] ACPI: FACS 000EEE00, 0040
[    0.000000] ACPI: PM-Timer IO Port: 0xee08
[    0.000000] Allocating PCI resources starting at 30000000 (gap: 20000000:dff80000)
[    0.000000] swsusp: Registered nosave memory region: 000000000009f000 - 00000000000a0000
[    0.000000] swsusp: Registered nosave memory region: 00000000000a0000 - 00000000000e0000
[    0.000000] swsusp: Registered nosave memory region: 00000000000e0000 - 00000000000ee000
[    0.000000] swsusp: Registered nosave memory region: 00000000000ee000 - 00000000000ef000
[    0.000000] swsusp: Registered nosave memory region: 00000000000ef000 - 0000000000100000
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 125826
[    0.000000] Kernel command line: BOOT_IMAGE=2.6.24-rc1-2avb root=LABEL=/ resume=LABEL=swap vga=791 1
[    0.000000] Enabling fast FPU save and restore... done.
[    0.000000] Enabling unmasked SIMD FPU exception support... done.
[    0.000000] Initializing CPU#0
[    0.000000] PID hash table entries: 2048 (order: 11, 8192 bytes)
[    0.000000] Detected 747.681 MHz processor.
[  303.225083] Console: colour dummy device 80x25
[  303.225109] console [tty0] enabled
[  303.227279] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
[  303.227304] ... MAX_LOCKDEP_SUBCLASSES:    8
[  303.227320] ... MAX_LOCK_DEPTH:          30
[  303.227334] ... MAX_LOCKDEP_KEYS:        2048
[  303.227350] ... CLASSHASH_SIZE:           1024
[  303.227365] ... MAX_LOCKDEP_ENTRIES:     8192
[  303.227380] ... MAX_LOCKDEP_CHAINS:      16384
[  303.227395] ... CHAINHASH_SIZE:          8192
[  303.227411]  memory used by lock dependency info: 1024 kB
[  303.227428]  per task-struct memory footprint: 1680 bytes
[  303.227447] ------------------------
[  303.227461] | Locking API testsuite:
[  303.227476] ----------------------------------------------------------------------------
[  303.227502]                                  | spin |wlock |rlock |mutex | wsem | rsem |
[  303.227528]   --------------------------------------------------------------------------
[  303.227580]                      A-A deadlock:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
[  303.230489]                  A-B-B-A deadlock:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
[  303.232699]              A-B-B-C-C-A deadlock:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
[  303.234953]              A-B-C-A-B-C deadlock:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
[  303.237211]          A-B-B-C-C-D-D-A deadlock:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
[  303.239539]          A-B-C-D-B-D-D-A deadlock:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
[  303.241863]          A-B-C-D-B-C-D-A deadlock:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
[  303.244200]                     double unlock:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
[  303.246338]                   initialize held:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
[  303.248462]                  bad unlock order:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
[  303.250656]   --------------------------------------------------------------------------
[  303.250683]               recursive read-lock:             |  ok  |             |  ok  |
[  303.251415]            recursive read-lock #2:             |  ok  |             |  ok  |
[  303.252149]             mixed read-write-lock:             |  ok  |             |  ok  |
[  303.252886]             mixed write-read-lock:             |  ok  |             |  ok  |
[  303.253622]   --------------------------------------------------------------------------
[  303.253649]      hard-irqs-on + irq-safe-A/12:  ok  |  ok  |  ok  |
[  303.254739]      soft-irqs-on + irq-safe-A/12:  ok  |  ok  |  ok  |
[  303.255830]      hard-irqs-on + irq-safe-A/21:  ok  |  ok  |  ok  |
[  303.256907]      soft-irqs-on + irq-safe-A/21:  ok  |  ok  |  ok  |
[  303.257985]        sirq-safe-A => hirqs-on/12:  ok  |  ok  |  ok  |
[  303.259067]        sirq-safe-A => hirqs-on/21:  ok  |  ok  |  ok  |
[  303.260147]          hard-safe-A + irqs-on/12:  ok  |  ok  |  ok  |
[  303.261226]          soft-safe-A + irqs-on/12:  ok  |  ok  |  ok  |
[  303.262310]          hard-safe-A + irqs-on/21:  ok  |  ok  |  ok  |
[  303.263390]          soft-safe-A + irqs-on/21:  ok  |  ok  |  ok  |
[  303.264473]     hard-safe-A + unsafe-B #1/123:  ok  |  ok  |  ok  |
[  303.265583]     soft-safe-A + unsafe-B #1/123:  ok  |  ok  |  ok  |
[  303.266693]     hard-safe-A + unsafe-B #1/132:  ok  |  ok  |  ok  |
[  303.267804]     soft-safe-A + unsafe-B #1/132:  ok  |  ok  |  ok  |
[  303.268912]     hard-safe-A + unsafe-B #1/213:  ok  |  ok  |  ok  |
[  303.270020]     soft-safe-A + unsafe-B #1/213:  ok  |  ok  |  ok  |
[  303.271131]     hard-safe-A + unsafe-B #1/231:  ok  |  ok  |  ok  |
[  303.272235]     soft-safe-A + unsafe-B #1/231:  ok  |  ok  |  ok  |
[  303.273341]     hard-safe-A + unsafe-B #1/312:  ok  |  ok  |  ok  |
[  303.274432]     soft-safe-A + unsafe-B #1/312:  ok  |  ok  |  ok  |
[  303.275523]     hard-safe-A + unsafe-B #1/321:  ok  |  ok  |  ok  |
[  303.276626]     soft-safe-A + unsafe-B #1/321:  ok  |  ok  |  ok  |
[  303.277731]     hard-safe-A + unsafe-B #2/123:  ok  |  ok  |  ok  |
[  303.278838]     soft-safe-A + unsafe-B #2/123:  ok  |  ok  |  ok  |
[  303.279950]     hard-safe-A + unsafe-B #2/132:  ok  |  ok  |  ok  |
[  303.281055]     soft-safe-A + unsafe-B #2/132:  ok  |  ok  |  ok  |
[  303.282163]     hard-safe-A + unsafe-B #2/213:  ok  |  ok  |  ok  |
[  303.283268]     soft-safe-A + unsafe-B #2/213:  ok  |  ok  |  ok  |
[  303.284379]     hard-safe-A + unsafe-B #2/231:  ok  |  ok  |  ok  |
[  303.285482]     soft-safe-A + unsafe-B #2/231:  ok  |  ok  |  ok  |
[  303.286589]     hard-safe-A + unsafe-B #2/312:  ok  |  ok  |  ok  |
[  303.287695]     soft-safe-A + unsafe-B #2/312:  ok  |  ok  |  ok  |
[  303.288806]     hard-safe-A + unsafe-B #2/321:  ok  |  ok  |  ok  |
[  303.289909]     soft-safe-A + unsafe-B #2/321:  ok  |  ok  |  ok  |
[  303.291017]       hard-irq lock-inversion/123:  ok  |  ok  |  ok  |
[  303.292130]       soft-irq lock-inversion/123:  ok  |  ok  |  ok  |
[  303.293245]       hard-irq lock-inversion/132:  ok  |  ok  |  ok  |
[  303.294352]       soft-irq lock-inversion/132:  ok  |  ok  |  ok  |
[  303.295467]       hard-irq lock-inversion/213:  ok  |  ok  |  ok  |
[  303.296572]       soft-irq lock-inversion/213:  ok  |  ok  |  ok  |
[  303.297684]       hard-irq lock-inversion/231:  ok  |  ok  |  ok  |
[  303.298788]       soft-irq lock-inversion/231:  ok  |  ok  |  ok  |
[  303.299900]       hard-irq lock-inversion/312:  ok  |  ok  |  ok  |
[  303.301009]       soft-irq lock-inversion/312:  ok  |  ok  |  ok  |
[  303.302125]       hard-irq lock-inversion/321:  ok  |  ok  |  ok  |
[  303.303230]       soft-irq lock-inversion/321:  ok  |  ok  |  ok  |
[  303.304342]       hard-irq read-recursion/123:  ok  |
[  303.304726]       soft-irq read-recursion/123:  ok  |
[  303.305109]       hard-irq read-recursion/132:  ok  |
[  303.305491]       soft-irq read-recursion/132:  ok  |
[  303.305874]       hard-irq read-recursion/213:  ok  |
[  303.306256]       soft-irq read-recursion/213:  ok  |
[  303.306637]       hard-irq read-recursion/231:  ok  |
[  303.307020]       soft-irq read-recursion/231:  ok  |
[  303.307404]       hard-irq read-recursion/312:  ok  |
[  303.307785]       soft-irq read-recursion/312:  ok  |
[  303.308168]       hard-irq read-recursion/321:  ok  |
[  303.308548]       soft-irq read-recursion/321:  ok  |
[  303.308932] -------------------------------------------------------
[  303.308955] Good, all 218 testcases passed! |
[  303.308970] ---------------------------------
[  303.310624] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
[  303.313635] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
[  303.419135] Memory: 496152k/507264k available (1876k kernel code, 10544k reserved, 889k data, 188k init, 0k highmem)
[  303.419231] virtual kernel memory layout:
[  303.419235]     fixmap  : 0xffff6000 - 0xfffff000   (  36 kB)
[  303.419239]     vmalloc : 0xdf800000 - 0xffff4000   ( 519 MB)
[  303.419243]     lowmem  : 0xc0000000 - 0xdef60000   ( 495 MB)
[  303.419247]       .init : 0xc03b6000 - 0xc03e5000   ( 188 kB)
[  303.419251]       .data : 0xc02d5179 - 0xc03b3964   ( 889 kB)
[  303.419255]       .text : 0xc0100000 - 0xc02d5179   (1876 kB)
[  303.419344] Checking if this processor honours the WP bit even in supervisor mode... Ok.
[  303.419637] SLUB: Genslabs=11, HWalign=32, Order=0-1, MinObjects=4, CPUs=1, Nodes=1
[  303.503050] Calibrating delay using timer specific routine.. 1498.37 BogoMIPS (lpj=2496594)
[  303.503282] Mount-cache hash table entries: 512
[  303.504435] CPU: After generic identify, caps: 0387f9ff 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[  303.504477] CPU: L1 I cache: 16K, L1 D cache: 16K
[  303.504505] CPU: L2 cache: 256K
[  303.504522] CPU serial number disabled.
[  303.504540] CPU: After all inits, caps: 0383f9ff 00000000 00000000 00000040 00000000 00000000 00000000 00000000
[  303.504581] Compat vDSO mapped to ffffe000.
[  303.504643] CPU: Intel Pentium III (Coppermine) stepping 0a
[  303.504679] Checking 'hlt' instruction... OK.
[  303.517166] Freeing SMP alternatives: 0k freed
[  303.517941] Early unpacking initramfs... done
[  303.596269] ACPI: Core revision 20070126
[  303.597243] ACPI: Looking for DSDT in initramfs... error, file /DSDT.aml not found.
[  303.607721] Parsing all Control Methods:
[  303.608072] Table [DSDT](id 0001) - 683 Objects with 60 Devices 195 Methods 10 Regions
[  303.608112]  tbxface-0598 [00] tb_load_namespace     : ACPI Tables successfully acquired
[  303.608154] ACPI: setting ELCR to 0200 (from 0a00)
[  303.608741] evxfevnt-0091 [00] enable                : Transition to ACPI mode successful
[  303.611271] net_namespace: 80 bytes
[  303.614501] NET: Registered protocol family 16
[  303.616234] ACPI: bus type pci registered
[  303.618374] PCI: PCI BIOS revision 2.10 entry at 0xfe5ae, last bus=5
[  303.618426] PCI: Using configuration type 1
[  303.618443] Setting up standard PCI resources
[  303.631658] evgpeblk-0956 [00] ev_create_gpe_block   : GPE 00 to 3F [_GPE] 8 regs on int 0x9
[  303.633845] evgpeblk-1052 [00] ev_initialize_gpe_bloc: Found 3 Wake, Enabled 0 Runtime GPEs in this block
[  303.633899] ACPI: EC: Look up EC in DSDT
[  303.641956] Completing Region/Field/Buffer/Package initialization:.....................................
[  303.644707] Initialized 5/10 Regions 0/0 Fields 16/16 Buffers 16/27 Packages (692 nodes)
[  303.644740] Initializing Device/Processor/Thermal objects by executing _INI methods:.
[  303.648254] Executed 1 _INI methods requiring 0 _STA executions (examined 64 objects)
[  303.648353] ACPI: Interpreter enabled
[  303.648372] ACPI: (supports S0 S3 S4 S5)
[  303.648528] ACPI: Using PIC for interrupt routing
[  303.681099] ACPI: PCI Root Bridge [PCI0] (0000:00)
[  303.682743] PCI quirk: region ee00-ee3f claimed by ali7101 ACPI
[  303.682779] PCI quirk: region ef00-ef1f claimed by ali7101 SMB
[  303.685124] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0._PRT]
[  303.685697] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.PCI1._PRT]
[  303.713157] ACPI: PCI Interrupt Link [LNKA] (IRQs 3 4 5 6 7 10 *11)
[  303.713940] ACPI: PCI Interrupt Link [LNKB] (IRQs 3 4 5 6 7 10 *11)
[  303.714653] ACPI: PCI Interrupt Link [LNKC] (IRQs 3 4 5 6 7 10 *11)
[  303.715366] ACPI: PCI Interrupt Link [LNKD] (IRQs 3 4 5 6 7 10 *11)
[  303.716079] ACPI: PCI Interrupt Link [LNKG] (IRQs 3 4 5 6 7 10 *11)
[  303.716840] ACPI: PCI Interrupt Link [LNKH] (IRQs 3 4 5 6 7 10 *11)
[  303.718169] ACPI: Power Resource [PFAN] (off)
[  303.718596] Linux Plug and Play Support v0.97 (c) Adam Belay
[  303.718876] pnp: PnP ACPI init
[  303.719022] ACPI: bus type pnp registered
[  303.743358] pnp: PnP ACPI: found 12 devices
[  303.743418] ACPI: ACPI bus type pnp unregistered
[  303.744491] PCI: Using ACPI for IRQ routing
[  303.744527] PCI: If a device doesn't work, try "pci=routeirq".  If it helps, post a report
[  303.769600] Time: tsc clocksource has been installed.
[  303.776607] system 00:00: iomem range 0x0-0x9ffff could not be reserved
[  303.776642] system 00:00: iomem range 0xe0000-0xeffff could not be reserved
[  303.776669] system 00:00: iomem range 0xf0000-0xfffff could not be reserved
[  303.776695] system 00:00: iomem range 0x100000-0x1ef5ffff could not be reserved
[  303.810399] PCI: Bridge: 0000:00:01.0
[  303.810442]   IO window: disabled.
[  303.810469]   MEM window: f7f00000-fdffffff
[  303.810492]   PREFETCH window: disabled.
[  303.810520] PCI: Bus 2, cardbus bridge: 0000:00:10.0
[  303.810538]   IO window: 00001000-000010ff
[  303.810560]   IO window: 00001400-000014ff
[  303.810583]   PREFETCH window: 30000000-33ffffff
[  303.810607]   MEM window: 34000000-37ffffff
[  303.810629] PCI: Bus 6, cardbus bridge: 0000:00:11.0
[  303.810647]   IO window: 00001800-000018ff
[  303.810669]   IO window: 00001c00-00001cff
[  303.810692]   PREFETCH window: 38000000-3bffffff
[  303.810715]   MEM window: 3c000000-3fffffff
[  303.810739] PCI: Bus 10, cardbus bridge: 0000:00:11.1
[  303.810756]   IO window: 00002000-000020ff
[  303.810778]   IO window: 00002400-000024ff
[  303.810801]   PREFETCH window: 40000000-43ffffff
[  303.810825]   MEM window: 44000000-47ffffff
[  303.810875] PCI: Setting latency timer of device 0000:00:01.0 to 64
[  303.810958] PCI: Enabling device 0000:00:10.0 (0000 -> 0003)
[  303.812563] ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 11
[  303.812601] PCI: setting IRQ 11 as level-triggered
[  303.812610] ACPI: PCI Interrupt 0000:00:10.0[A] -> Link [LNKC] -> GSI 11 (level, low) -> IRQ 11
[  303.812691] PCI: Enabling device 0000:00:11.0 (0000 -> 0003)
[  303.813931] ACPI: PCI Interrupt Link [LNKA] enabled at IRQ 11
[  303.813959] ACPI: PCI Interrupt 0000:00:11.0[A] -> Link [LNKA] -> GSI 11 (level, low) -> IRQ 11
[  303.814036] PCI: Enabling device 0000:00:11.1 (0000 -> 0003)
[  303.815209] ACPI: PCI Interrupt Link [LNKB] enabled at IRQ 11
[  303.815234] ACPI: PCI Interrupt 0000:00:11.1[B] -> Link [LNKB] -> GSI 11 (level, low) -> IRQ 11
[  303.815342] NET: Registered protocol family 2
[  303.846665] IP route cache hash table entries: 4096 (order: 2, 16384 bytes)
[  303.848237] TCP established hash table entries: 16384 (order: 7, 589824 bytes)
[  303.854394] TCP bind hash table entries: 16384 (order: 7, 589824 bytes)
[  303.860535] TCP: Hash tables configured (established 16384 bind 16384)
[  303.860761] TCP reno registered
[  303.870516] checking if image is initramfs... it is
[  304.007594] Freeing initrd memory: 545k freed
[  304.011682] audit: initializing netlink socket (disabled)
[  304.011874] audit(1193416518.593:1): initialized
[  304.033288] io scheduler noop registered
[  304.033350] io scheduler anticipatory registered
[  304.033368] io scheduler deadline registered
[  304.033955] io scheduler cfq registered (default)
[  304.034066] Activating ISA DMA hang workarounds.
[  304.034138] Boot video device is 0000:01:00.0
[  304.035247] vesafb: framebuffer at 0xfc000000, mapped to 0xdf880000, using 3072k, total 16384k
[  304.035291] vesafb: mode is 1024x768x16, linelength=2048, pages=9
[  304.035311] vesafb: protected mode interface info at c000:775e
[  304.035332] vesafb: pmi: set display start = c00c777f, set palette = c00c77e2
[  304.035353] vesafb: scrolling: redraw
[  304.035371] vesafb: Truecolor: size=0:5:6:5, shift=0:11:5:0
[  304.105347] Console: switching to colour frame buffer device 128x48
[  304.168093] fb0: VESA VGA frame buffer device
[  304.312823] Switched to high resolution mode on CPU 0
[  304.418965] Real Time Clock Driver v1.12ac
[  304.425678] RAMDISK driver initialized: 16 RAM disks of 32000K size 1024 blocksize
[  304.427470] e100: Intel(R) PRO/100 Network Driver, 3.5.23-k4-NAPI
[  304.428289] e100: Copyright(c) 1999-2006 Intel Corporation
[  304.431401] ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 11
[  304.432213] ACPI: PCI Interrupt 0000:00:0a.0[A] -> Link [LNKD] -> GSI 11 (level, low) -> IRQ 11
[  304.462107] e100: eth0: e100_probe: addr 0xf7efd000, irq 11, MAC addr 00:00:39:d7:14:a1
[  304.463387] console [netcon0] enabled
[  309.197997] Clocksource tsc unstable (delta = 4686935420 ns)
[  309.225431] Time: acpi_pm clocksource has been installed.
[  309.252674] netconsole: network logging started
[  309.280755] PNP: PS/2 Controller [PNP0303:KBC,PNP0f13:PS2M] at 0x60,0x64 irq 1,12
[  309.313835] serio: i8042 KBD port at 0x60,0x64 irq 1
[  309.341114] serio: i8042 AUX port at 0x60,0x64 irq 12
[  309.369456] mice: PS/2 mouse device common for all mice
[  309.396649] cpuidle: using governor ladder
[  309.422884] cpuidle: using governor menu
[  309.448830] TCP cubic registered
[  309.475051] NET: Registered protocol family 1
[  309.500307] Using IPI Shortcut mode
[  309.526132] BIOS EDD facility v0.16 2004-Jun-25, 16 devices found
[  309.558398] Freeing unused kernel memory: 188k freed
[  309.583631] Write protecting the kernel read-only data: 716k
[  309.615922] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0
[  309.727501] SCSI subsystem initialized
[  309.817382] libata version 3.00 loaded.
[  309.851886] ACPI: Unable to derive IRQ for device 0000:00:04.0
[  309.877910] ACPI: PCI Interrupt 0000:00:04.0[A]: no GSI
[  309.904896] scsi0 : pata_ali
[  309.931721] scsi1 : pata_ali
[  309.959733] ata1: PATA max UDMA/66 cmd 0x1f0 ctl 0x3f6 bmdma 0xeff0 irq 14
[  309.985707] ata2: PATA max UDMA/66 cmd 0x170 ctl 0x376 bmdma 0xeff8 irq 15
[  310.171553] ata1.00: ATA-5: IC25N020ATDA04-0, DA3OA70A, max UDMA/100
[  310.196850] ata1.00: 39070080 sectors, multi 0: LBA
[  310.221883] ata1.00: limited to UDMA/33 due to 40-wire cable
[  310.258042] ata1.00: configured for UDMA/33
[  310.634459] ata2.00: ATAPI: TOSHIBA DVD-ROM SD-C2502, 1313, max UDMA/33
[  310.841030] ata2.00: configured for UDMA/33
[  310.866784] scsi 0:0:0:0: Direct-Access     ATA      IC25N020ATDA04-0 DA3O PQ: 0 ANSI: 5
[  316.392425] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
[  316.418238] ata2.00: cmd a0/01:00:00:60:00/00:00:00:00:00/a0 tag 0 cdb 0x12 data 96 in
[  316.418243]          res 40/00:02:00:24:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
[  316.469416] ata2.00: status: { DRDY }
[  316.494586] ata2: soft resetting link
[  317.062563] ata2.00: configured for UDMA/33
[  317.087277] ata2: EH complete
[  322.607309] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
[  322.631662] ata2.00: cmd a0/01:00:00:60:00/00:00:00:00:00/a0 tag 0 cdb 0x12 data 96 in
[  322.631668]          res 40/00:02:00:24:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
[  322.680571] ata2.00: status: { DRDY }
[  322.704916] ata2: soft resetting link
[  323.240806] ata2.00: configured for UDMA/33
[  323.264245] ata2: EH complete
[  328.785529] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
[  328.809601] ata2.00: cmd a0/01:00:00:60:00/00:00:00:00:00/a0 tag 0 cdb 0x12 data 96 in
[  328.809607]          res 40/00:02:00:24:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
[  328.858600] ata2.00: status: { DRDY }
[  328.883176] ata2: soft resetting link
[  329.449029] ata2.00: configured for UDMA/33
[  329.473579] ata2: EH complete
[  334.993757] ata2.00: limiting speed to UDMA/25:PIO4
[  335.017842] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
[  335.042286] ata2.00: cmd a0/01:00:00:60:00/00:00:00:00:00/a0 tag 0 cdb 0x12 data 96 in
[  335.042292]          res 40/00:02:00:24:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
[  335.090851] ata2.00: status: { DRDY }
[  335.114115] ata2: soft resetting link
[  335.673939] ata2.00: configured for UDMA/25
[  335.697111] ata2: EH complete
[  335.720273] scsi scan: 96 byte inquiry failed.  Consider BLIST_INQUIRY_36 for this device
[  335.755953] scsi 1:0:0:0: CD-ROM            TOSHIBA  DVD-ROM SD-C2502 1313 PQ: 0 ANSI: 5
[  335.816185] sd 0:0:0:0: [sda] 39070080 512-byte hardware sectors (20004 MB)
[  335.841549] sd 0:0:0:0: [sda] Write Protect is off
[  335.866399] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
[  335.866553] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[  335.892874] sd 0:0:0:0: [sda] 39070080 512-byte hardware sectors (20004 MB)
[  335.918566] sd 0:0:0:0: [sda] Write Protect is off
[  335.943827] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
[  335.944022] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[  335.969995]  sda: sda1 sda2
[  336.258606] sd 0:0:0:0: [sda] Attached SCSI disk
[  336.692078] swsusp: Marking nosave pages: 000000000009f000 - 0000000000100000
[  336.692107] swsusp: Basic memory bitmaps created
[  336.727536] swsusp: Basic memory bitmaps freed
[  336.875336] ReiserFS: sda2: found reiserfs format "3.6" with standard journal
[  336.899115] ReiserFS: sda2: using ordered data mode
[  336.939277] ReiserFS: sda2: journal params: device sda2, size 8192, journal first block 18, max trans len 1024, max batch 900, max commit age 30, max trans age 30
[  336.998056] ReiserFS: sda2: checking transaction log (sda2)
[  337.055288] ReiserFS: sda2: Using r5 hash to sort names
[  346.142024] sd 0:0:0:0: Attached scsi generic sg0 type 0
[  346.142148] scsi 1:0:0:0: Attached scsi generic sg1 type 5
[  347.103036] PCI: Enabling device 0000:00:08.0 (0000 -> 0001)
[  347.103470] ALi_M1535: initialized. timeout=60 sec (nowayout=0)
[  347.566440] Linux agpgart interface v0.102
[  347.904498] agpgart: Detected ALi M1644 chipset
[  347.914590] agpgart: AGP aperture is 64M @ 0xf0000000
[  349.194540] Serial: 8250/16550 driver $Revision: 1.90 $ 4 ports, IRQ sharing enabled
[  349.206916] usbcore: registered new interface driver usbfs
[  349.207550] usbcore: registered new interface driver hub
[  349.241965] usbcore: registered new device driver usb
[  349.447534] Yenta: CardBus bridge found at 0000:00:10.0 [12a3:ab01]
[  349.447606] Yenta: Using CSCINT to route CSC interrupts to PCI
[  349.447613] Yenta: Routing CardBus interrupts to PCI
[  349.447627] Yenta TI: socket 0000:00:10.0, mfunc 0x01000002, devctl 0x60
[  349.677393] Yenta: ISA IRQ mask 0x0000, PCI irq 11
[  349.677413] Socket status: 30000059
[  349.680796] Yenta: CardBus bridge found at 0000:00:11.0 [1179:0001]
[  349.808051] Yenta: ISA IRQ mask 0x0498, PCI irq 11
[  349.808068] Socket status: 30000007
[  349.813867] serial 00:09: activated
[  349.822493] Yenta: CardBus bridge found at 0000:00:11.1 [1179:0001]
[  349.873081] ohci_hcd: 2006 August 04 USB 1.1 'Open' Host Controller (OHCI) Driver
[  349.946966] Yenta: ISA IRQ mask 0x04b8, PCI irq 11
[  349.946986] Socket status: 30000007
[  349.953591] ACPI: PCI Interrupt Link [LNKG] enabled at IRQ 11
[  349.953617] ACPI: PCI Interrupt 0000:00:02.0[A] -> Link [LNKG] -> GSI 11 (level, low) -> IRQ 11
[  349.953701] ohci_hcd 0000:00:02.0: OHCI Host Controller
[  349.958228] ohci_hcd 0000:00:02.0: new USB bus registered, assigned bus number 1
[  349.958338] ohci_hcd 0000:00:02.0: irq 11, io mem 0xf7eff000
[  350.037330] usb usb1: configuration #1 chosen from 1 choice
[  350.038024] hub 1-0:1.0: USB hub found
[  350.038186] hub 1-0:1.0: 3 ports detected
[  350.148633] NET: Registered protocol family 23
[  350.312853] pccard: PCMCIA card inserted into slot 0
[  350.611815] Detected unconfigured Toshiba laptop with ALi ISA bridge SMSC IrDA chip, pre-configuring device.
[  350.611854] Activated ALi 1533 ISA bridge port 0x02e8.
[  350.611869] Activated ALi 1533 ISA bridge port 0x02f8.
[  350.612079] found SMC SuperIO Chip (devid=0x5a rev=00 base=0x002e): LPC47N227
[  350.612093] smsc_superio_flat(): IrDA not enabled
[  350.612120] smsc_superio_flat(): fir: 0x2f8, sir: 0x2e8, dma: 03, irq: 7, mode: 0x02
[  350.612159] SMsC IrDA Controller found
[  350.612162]  IrCC version 2.0, firport 0x2f8, sirport 0x2e8 dma=3, irq=7
[  350.612372] No transceiver found. Defaulting to Fast pin select
[  350.614406] IrDA: Registered device irda0
[  350.937451] ACPI: PCI Interrupt Link [LNKH] enabled at IRQ 11
[  350.937477] ACPI: PCI Interrupt 0000:00:06.0[A] -> Link [LNKH] -> GSI 11 (level, low) -> IRQ 11
[  353.770136] cs: IO port probe 0x100-0x3af: excluding 0x200-0x207 0x220-0x22f 0x330-0x337 0x388-0x38f
[  353.774138] cs: IO port probe 0x100-0x3af: excluding 0x200-0x207 0x220-0x22f 0x330-0x337 0x388-0x38f
[  353.777421] cs: IO port probe 0x3e0-0x4ff: excluding 0x408-0x40f 0x480-0x48f 0x4d0-0x4d7
[  353.778956] cs: IO port probe 0x820-0x8ff: clean.
[  353.780268] cs: IO port probe 0xc00-0xcf7: clean.
[  353.782174] cs: IO port probe 0x3e0-0x4ff: excluding 0x408-0x40f 0x480-0x48f 0x4d0-0x4d7
[  353.783672] cs: IO port probe 0x820-0x8ff: clean.
[  353.785168] cs: IO port probe 0xc00-0xcf7: clean.
[  353.787462] cs: IO port probe 0xa00-0xaff: clean.
[  353.789599] cs: IO port probe 0xa00-0xaff: clean.
[  353.838489] cs: memory probe 0xa0000000-0xa0ffffff: clean.
[  353.897943] pcmcia: registering new device pcmcia0.0
[  354.411093] cs: IO port probe 0x100-0x3af: excluding 0x200-0x207 0x220-0x22f 0x330-0x337 0x388-0x38f
[  354.414420] cs: IO port probe 0x3e0-0x4ff: excluding 0x408-0x40f 0x480-0x48f 0x4d0-0x4d7
[  354.415964] cs: IO port probe 0x820-0x8ff: clean.
[  354.417278] cs: IO port probe 0xc00-0xcf7: clean.
[  354.419665] cs: IO port probe 0xa00-0xaff: clean.
[  354.762122] wlags49_h1_cs v7.18 for PCMCIA, 03/31/2004 14:31:00 by Agere Systems, http://www.agere.com
[  354.762145] *** Modified for kernel 2.6 by Andrey Borzenkov <arvidjaar@mail.ru> $Revision: 39 $
[  354.762153] *** Station Mode (STA) Support: YES
[  354.762158] *** Access Point Mode (AP) Support: YES
[  355.699490] eth1: PRI 31 variant 2 version 9.48
[  355.699559] eth1: NIC 5 variant 2 version 1.02
[  355.708777] eth1: Wireless, io_addr 0x100, irq 11, mac_address 00:02:2D:26:95:6C
[  376.928553] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
[  376.928586] ata2.00: cmd a0/01:00:00:80:00/00:00:00:00:00/a0 tag 0 cdb 0x5a data 128 in
[  376.928591]          res 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
[  376.928601] ata2.00: status: { DRDY }
[  376.928633] ata2: soft resetting link
[  377.442049] ata2.00: configured for UDMA/25
[  377.442110] ata2: EH complete
[  407.433185] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
[  407.433213] ata2.00: cmd a0/01:00:00:80:00/00:00:00:00:00/a0 tag 0 cdb 0x5a data 128 in
[  407.433219]          res 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
[  407.433229] ata2.00: status: { DRDY }
[  407.433257] ata2: soft resetting link
[  407.946697] ata2.00: configured for UDMA/25
[  407.946750] ata2: EH complete
[  437.937815] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
[  437.937842] ata2.00: cmd a0/01:00:00:80:00/00:00:00:00:00/a0 tag 0 cdb 0x5a data 128 in
[  437.937848]          res 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
[  437.937857] ata2.00: status: { DRDY }
[  437.937882] ata2: soft resetting link
[  438.497994] ata2.00: configured for UDMA/25
[  438.498045] ata2: EH complete
[  468.489100] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
[  468.489121] ata2.00: cmd a0/01:00:00:80:00/00:00:00:00:00/a0 tag 0 cdb 0x5a data 128 in
[  468.489127]          res 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
[  468.489136] ata2.00: status: { DRDY }
[  468.489160] ata2: soft resetting link
[  469.032626] ata2.00: configured for UDMA/25
[  469.032705] ata2: EH complete
[  469.032759] sr0: scsi-1 drive
[  469.032770] Uniform CD-ROM driver Revision: 3.20
[  469.033328] sr 1:0:0:0: Attached scsi CD-ROM sr0
[  470.185756] Toshiba System Managment Mode driver v1.11 26/9/2001
[  470.271788] Non-volatile memory driver v1.2
[  470.465527] input: ImPS/2 Generic Wheel Mouse as /devices/platform/i8042/serio1/input/input1
[  471.419177] ACPI: AC Adapter [ADP1] (on-line)
[  471.493155] ACPI: Battery Slot [BAT1] (battery present)
[  471.499597] ACPI: Battery Slot [BAT2] (battery absent)
[  471.553747] input: Power Button (FF) as /devices/virtual/input/input2
[  471.578713] ACPI: Power Button (FF) [PWRF]
[  471.579281] input: Lid Switch as /devices/virtual/input/input3
[  471.591901] ACPI: Lid Switch [LID]
[  471.623844] ACPI: Transitioning device [FAN] to D3
[  471.623862] ACPI: Transitioning device [FAN] to D3
[  471.623894] ACPI: Fan [FAN] (off)
[  471.841195] ACPI: CPU0 (power states: C1[C1] C2[C2])
[  471.919037] ACPI: Thermal Zone [THRM] (49 C)
[  472.074629] toshiba_acpi: Toshiba Laptop ACPI Extras version 0.18
[  472.074823] toshiba_acpi:     HCI method: \_SB_.VALD.GHCI
[  472.193674] input: Video Bus as /devices/virtual/input/input4
[  472.218376] ACPI: Video Device [VGA] (multi-head: yes  rom: yes  post: no)
[  472.631269] Marking TSC unstable due to: TSC halts in idle.
[  472.767030] Uniform Multi-Platform E-IDE driver Revision: 7.00alpha2
[  472.767068] ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx
[  472.951037] device-mapper: uevent: version 1.0.3
[  472.951610] device-mapper: ioctl: 4.12.0-ioctl (2007-10-02) initialised: dm-devel@redhat.com
[  473.318896] loop: module loaded
[  475.804272] Adding 500432k swap on /dev/sda1.  Priority:-1 extents:1 across:500432k
Comment 26 Alan 2007-10-26 12:31:25 UTC
What happens if you specify libata.dma=1

Alan
Comment 27 Andrey Borzenkov 2007-10-26 23:29:14 UTC
(In reply to comment #26)
> What happens if you specify libata.dma=1
> 

this works but there is nothing new - we already know that it works if DMA is disabled for ATAPI.
Comment 28 Alan 2007-12-03 10:29:53 UTC
Further patches pushed to Jeff and heading upstream.
Comment 29 Andrey Borzenkov 2007-12-04 12:23:51 UTC
rc4 passes detection step but attempt to access media in a system results in constant stream of errors and process hangs.

[ 6810.277874] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
[ 6810.277927] ata2.00: cmd a0/01:00:00:00:10/00:00:00:00:00/a0 tag 0 dma 4096 in
[ 6810.277932]          cdb 28 00 00 00 00 10 00 00  02 00 00 00 00 00 00 00
[ 6810.277936]          res 40/00:02:00:0c:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
[ 6810.277947] ata2.00: status: { DRDY }
[ 6810.278064] ata2: soft resetting link
[ 6810.305981] ata2.00: configured for UDMA/33
[ 6810.306076] ata2: EH complete
[ 6813.519346] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
[ 6813.519403] ata2.00: cmd a0/01:00:00:00:10/00:00:00:00:00/a0 tag 0 dma 4096 in
[ 6813.519408]          cdb 28 00 00 00 00 10 00 00  02 00 00 00 00 00 00 00
[ 6813.519413]          res 40/00:02:00:0c:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
[ 6813.519423] ata2.00: status: { DRDY }
[ 6813.519538] ata2: soft resetting link
[ 6813.547405] ata2.00: configured for UDMA/33
[ 6813.547504] ata2: EH complete
[ 6824.101296] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
[ 6824.101351] ata2.00: cmd a0/01:00:00:00:10/00:00:00:00:00/a0 tag 0 dma 4096 in
[ 6824.101357]          cdb 28 00 00 00 00 10 00 00  02 00 00 00 00 00 00 00
[ 6824.101361]          res 40/00:02:00:0c:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
[ 6824.101372] ata2.00: status: { DRDY }
[ 6824.101486] ata2: soft resetting link
[ 6824.356713] ata2.00: configured for UDMA/33
[ 6824.356806] ata2: EH complete
[ 6838.421101] ata2.00: limiting speed to UDMA/25:PIO4
[ 6838.421135] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
[ 6838.421167] ata2.00: cmd a0/01:00:00:00:10/00:00:00:00:00/a0 tag 0 dma 4096 in
[ 6838.421172]          cdb 28 00 00 00 00 10 00 00  02 00 00 00 00 00 00 00
[ 6838.421176]          res 40/00:02:00:0c:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
[ 6838.421187] ata2.00: status: { DRDY }
[ 6838.421308] ata2: soft resetting link
[ 6838.510464] ata2.00: configured for UDMA/25
[ 6838.510566] sr 1:0:0:0: [sr0] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE,SUGGEST_OK
[ 6838.510580] sr 1:0:0:0: [sr0] Sense Key : Aborted Command [current] [descriptor]
[ 6838.510596] Descriptor sense data with sense descriptors (in hex):
[ 6838.510604]         72 0b 00 00 00 00 00 0e 09 0c 00 00 00 02 00 00
[ 6838.510632]         00 0c 00 00 a0 40
[ 6838.510646] sr 1:0:0:0: [sr0] Add. Sense: No additional sense information
[ 6838.510662] end_request: I/O error, dev sr0, sector 64
[ 6838.510681] Buffer I/O error on device sr0, logical block 8
[ 6838.510764] ata2: EH complete
[ 6844.245058] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
[ 6844.245110] ata2.00: cmd a0/01:00:00:00:10/00:00:00:00:00/a0 tag 0 dma 4096 in
[ 6844.245115]          cdb 28 00 00 00 00 10 00 00  02 00 00 00 00 00 00 00
[ 6844.245119]          res 40/00:02:00:0c:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
[ 6844.245130] ata2.00: status: { DRDY }
[ 6844.245246] ata2: soft resetting link
[ 6844.376679] ata2.00: configured for UDMA/25
[ 6844.376778] ata2: EH complete
[ 6849.838197] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
[ 6849.838248] ata2.00: cmd a0/01:00:00:00:10/00:00:00:00:00/a0 tag 0 dma 4096 in
[ 6849.838253]          cdb 28 00 00 00 00 10 00 00  02 00 00 00 00 00 00 00
[ 6849.838258]          res 40/00:02:00:0c:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
[ 6849.838269] ata2.00: status: { DRDY }
[ 6849.838390] ata2: soft resetting link
[ 6849.882527] ata2.00: configured for UDMA/25
[ 6849.882632] ata2: EH complete

OK it finally got killed after error recovery gave up ...
Comment 30 Andrey Borzenkov 2008-02-24 04:52:01 UTC
2.6.25-rc2 status update. pata_ali still fails DMA but libata now at least falls back to PIO which allows request to complete.

I ask myself whether IDE is actually using DMA in this case. Not sure how to check it though (on boot both state "configured for DMA33")
Comment 31 Tejun Heo 2008-03-03 20:38:35 UTC
You can check by running "hdparm -I" and looking at the selected transfer mode.  I'm fairly sure IDE is using DMA.  pata_ali has trouble doing ATAPI DMAs.  I have the hardware and spent days trying to debug it but haven't been able to come up with solution yet.  I'm planning on giving it another shot but don't know when that will be at the moment.  Thanks.

Ah.. also, can you please post the boot log from 2.6.25-rc2?  I wanna look how libata EH actually responded to the situation.
Comment 32 Andrey Borzenkov 2008-03-09 00:57:41 UTC
Created attachment 15184 [details]
dmesg with pata_ali from 2.6.25-rc4

Here you are - it is dmesg from 2.6.25-rc4.
Comment 33 Tejun Heo 2008-03-09 05:37:52 UTC
Thanks.  Good to know that at least something works as expected.  :-P