Bug 8918 (ata_frozen) - (ata_piix PATA) DVD-Burning fails: ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
Summary: (ata_piix PATA) DVD-Burning fails: ata5.00: exception Emask 0x0 SAct 0x0 SErr...
Status: RESOLVED OBSOLETE
Alias: ata_frozen
Product: IO/Storage
Classification: Unclassified
Component: Serial ATA (show other bugs)
Hardware: All Linux
: P1 normal
Assignee: Jeff Garzik
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2007-08-21 12:48 UTC by Bjoern Olausson
Modified: 2013-12-23 18:37 UTC (History)
4 users (show)

See Also:
Kernel Version: 2.6.23
Subsystem:
Regression: No
Bisected commit-id:


Attachments
dvd.patch (1.84 KB, patch)
2007-09-26 02:03 UTC, Bjoern Olausson
Details | Diff
dvd-proper.patch (1.60 KB, patch)
2007-09-26 04:49 UTC, Bjoern Olausson
Details | Diff
atapi-dma-for-rw-only.patch (1.15 KB, patch)
2007-10-18 07:29 UTC, Tejun Heo
Details | Diff
debug.patch (1.28 KB, patch)
2007-10-29 03:39 UTC, Tejun Heo
Details | Diff
dmesg-ICH7.log (46.56 KB, application/octet-stream)
2008-04-10 10:30 UTC, Bjoern Olausson
Details
dmesg-jmicron.log (49.08 KB, application/octet-stream)
2008-04-10 10:30 UTC, Bjoern Olausson
Details

Description Bjoern Olausson 2007-08-21 12:48:25 UTC
Most recent kernel where this bug did not occur:
Last one I am shure of 2.6.21.5


Distribution:
Gentoo


Hardware Environment:
00:00.0 Host bridge: Intel Corporation 975X Express Memory Controller Hub (rev c0)
00:01.0 PCI bridge: Intel Corporation 975X Express PCI Express Root Port (rev c0)
00:1b.0 Audio device: Intel Corporation 82801G (ICH7 Family) High Definition Audio Controller (rev 01)
00:1c.0 PCI bridge: Intel Corporation 82801G (ICH7 Family) PCI Express Port 1 (rev 01)
00:1c.3 PCI bridge: Intel Corporation 82801G (ICH7 Family) PCI Express Port 4 (rev 01)
00:1d.0 USB Controller: Intel Corporation 82801G (ICH7 Family) USB UHCI #1 (rev 01)
00:1d.1 USB Controller: Intel Corporation 82801G (ICH7 Family) USB UHCI #2 (rev 01)
00:1d.2 USB Controller: Intel Corporation 82801G (ICH7 Family) USB UHCI #3 (rev 01)
00:1d.3 USB Controller: Intel Corporation 82801G (ICH7 Family) USB UHCI #4 (rev 01)
00:1d.7 USB Controller: Intel Corporation 82801G (ICH7 Family) USB2 EHCI Controller (rev 01)
00:1e.0 PCI bridge: Intel Corporation 82801 PCI Bridge (rev e1)
00:1f.0 ISA bridge: Intel Corporation 82801GB/GR (ICH7 Family) LPC Interface Bridge (rev 01)
00:1f.1 IDE interface: Intel Corporation 82801G (ICH7 Family) IDE Controller (rev 01)
00:1f.2 SATA controller: Intel Corporation 82801GR/GH (ICH7 Family) Serial ATA Storage Controller AHCI (rev 01)
00:1f.3 SMBus: Intel Corporation 82801G (ICH7 Family) SMBus Controller (rev 01)
01:00.0 Multimedia audio controller: Creative Labs Unknown device 0005
01:01.0 Multimedia video controller: Brooktree Corporation Bt878 Video Capture (rev 11)
01:01.1 Multimedia controller: Brooktree Corporation Bt878 Audio Capture (rev 11)
01:02.0 Ethernet controller: Atheros Communications, Inc. AR5212 802.11abg NIC (rev 01)
01:03.0 FireWire (IEEE 1394): Texas Instruments TSB43AB22/A IEEE-1394a-2000 Controller (PHY/Link)
02:00.0 Ethernet controller: Marvell Technology Group Ltd. 88E8053 PCI-E Gigabit Ethernet Controller (rev 20)
04:00.0 VGA compatible controller: nVidia Corporation G70 [GeForce 7600 GT] (rev a1)

 lshw -short
H/W path                   Device       Class       Description
===============================================================
                                        system      P5W DH Deluxe
/0                                      bus         P5W DH Deluxe
/0/0                                    memory      64KB BIOS
/0/4                                    processor   Intel(R) Core(TM)2 CPU          6600  @ 2.40GHz
/0/4/5                                  memory      32KB L1 cache
/0/4/6                                  memory      4MB L2 cache
/0/4/7                                  memory      L3 cache
/0/3c                                   memory      2GB System Memory
/0/3c/0                                 memory      1GB DIMM SDRAM Synchronous
/0/3c/1                                 memory      DIMM [empty]
/0/3c/2                                 memory      1GB DIMM SDRAM Synchronous
/0/3c/3                                 memory      DIMM [empty]
/0/100                                  bridge      975X Express Memory Controller Hub
/0/100/1                                bridge      975X Express PCI Express Root Port
/0/100/1/0                              display     G70 [GeForce 7600 GT]
/0/100/1b                               multimedia  82801G (ICH7 Family) High Definition Audio Controller
/0/100/1c                               bridge      82801G (ICH7 Family) PCI Express Port 1
/0/100/1c.3                             bridge      82801G (ICH7 Family) PCI Express Port 4
/0/100/1c.3/0              eth0         network     88E8053 PCI-E Gigabit Ethernet Controller
/0/100/1d                               bus         82801G (ICH7 Family) USB UHCI #1
/0/100/1d/1                usb2         bus         UHCI Host Controller
/0/100/1d/1/2                           generic     USB RECEIVER
/0/100/1d.1                             bus         82801G (ICH7 Family) USB UHCI #2
/0/100/1d.1/1              usb3         bus         UHCI Host Controller
/0/100/1d.1/1/1                         generic     ASUS DH Remote
/0/100/1d.1/1/2                         bus         Logitech BT Mini-Receiver
/0/100/1d.1/1/2/2                       generic     Logitech BT Mini-Receiver
/0/100/1d.1/1/2/3                       generic     Logitech BT Mini-Receiver
/0/100/1d.2                             bus         82801G (ICH7 Family) USB UHCI #3
/0/100/1d.2/1              usb4         bus         UHCI Host Controller
/0/100/1d.2/1/1                         generic     Bluetooth Device
/0/100/1d.3                             bus         82801G (ICH7 Family) USB UHCI #4
/0/100/1d.3/1              usb5         bus         UHCI Host Controller
/0/100/1d.7                             bus         82801G (ICH7 Family) USB2 EHCI Controller
/0/100/1d.7/1              usb1         bus         EHCI Host Controller
/0/100/1d.7/1/1                         bus         USB2.0 Hub
/0/100/1d.7/1/1/1                       generic     USB Receiver
/0/100/1d.7/1/1/2                       generic     iP5200
/0/100/1d.7/1/1/3                       generic     Astra 2200/2200SU
/0/100/1d.7/1/7                         bus         USB2.0 Hub
/0/100/1d.7/1/7/1                       bus         USB2.0 Hub
/0/100/1d.7/1/7/2          scsi6        generic     USB Storage
/0/100/1d.7/1/7/2/0.0.0    /dev/sdc     disk        STORAGE DEVICE
/0/100/1d.7/1/7/2/0.0.0/0  /dev/sdc     disk
/0/100/1d.7/1/7/2/0.0.1    /dev/sdd     disk        STORAGE DEVICE
/0/100/1d.7/1/7/2/0.0.1/0  /dev/sdd     disk
/0/100/1d.7/1/7/2/0.0.2    /dev/sde     disk        STORAGE DEVICE
/0/100/1d.7/1/7/2/0.0.2/0  /dev/sde     disk
/0/100/1d.7/1/7/2/0.0.3    /dev/sdf     disk        STORAGE DEVICE
/0/100/1d.7/1/7/2/0.0.3/0  /dev/sdf     disk
/0/100/1d.7/1/7/3                       generic     RTL8187_Wireless
/0/100/1e                               bridge      82801 PCI Bridge
/0/100/1e/0                             multimedia  SB X-Fi
/0/100/1e/1                             multimedia  Bt878 Video Capture
/0/100/1e/1.1                           multimedia  Bt878 Audio Capture
/0/100/1e/2                wifi0        network     AR5212 802.11abg NIC
/0/100/1e/3                             bus         TSB43AB22/A IEEE-1394a-2000 Controller (PHY/Link)
/0/100/1f                               bridge      82801GB/GR (ICH7 Family) LPC Interface Bridge
/0/100/1f.1                scsi4        storage     82801G (ICH7 Family) IDE Controller
/0/100/1f.1/0.0.0          /dev/cdrom   disk        DVDR   PX-760A
/0/100/1f.1/0.0.0/0        /dev/cdrom   disk
/0/100/1f.1/0.1.0          /dev/cdrom1  disk        DVD-ROM PX-130A
/0/100/1f.2                scsi0        storage     82801GR/GH (ICH7 Family) Serial ATA Storage Controller AHCI
/0/100/1f.2/0              /dev/sda     disk        69GB WDC WD740ADFD-00
/0/100/1f.2/0/1            /dev/sda1    volume      47MB Linux filesystem partition
/0/100/1f.2/0/2            /dev/sda2    volume      956MB Linux swap / Solaris partition
/0/100/1f.2/0/3            /dev/sda3    volume      68GB Linux filesystem partition
/0/100/1f.2/1              /dev/sdb     disk        69GB External Disk 0
/0/100/1f.2/1/1            /dev/sdb1    volume      69GB HPFS/NTFS partition
/0/100/1f.3                             bus         82801G (ICH7 Family) SMBus Controller
/1                         irlan0       network     Ethernet interface



Software Environment:
Portage 2.1.2.12 (default-linux/amd64/2007.0/desktop, gcc-4.1.2, glibc-2.5-r4, 2.6.22.4 x86_64)
=================================================================
System uname: 2.6.22.4 x86_64 Intel(R) Core(TM)2 CPU 6600 @ 2.40GHz
Gentoo Base System release 1.12.9
Timestamp of tree: Tue, 21 Aug 2007 12:50:01 +0000
distcc 2.18.3 x86_64-pc-linux-gnu (protocols 1 and 2) (default port 3632) [disabled]
ccache version 2.4 [enabled]
dev-java/java-config: 1.3.7, 2.0.33-r1
dev-lang/python:     2.4.4-r4
dev-python/pycrypto: 2.0.1-r6
dev-util/ccache:     2.4-r7
sys-apps/sandbox:    1.2.17
sys-devel/autoconf:  2.13, 2.61
sys-devel/automake:  1.4_p6, 1.5, 1.6.3, 1.7.9-r1, 1.8.5-r3, 1.9.6-r2, 1.10
sys-devel/binutils:  2.17
sys-devel/gcc-config: 1.3.16
sys-devel/libtool:   1.5.24
virtual/os-headers:  2.6.21
ACCEPT_KEYWORDS="amd64"
AUTOCLEAN="yes"
CBUILD="x86_64-pc-linux-gnu"
CFLAGS="-march=nocona -O2 -pipe -fomit-frame-pointer"
CHOST="x86_64-pc-linux-gnu"
CONFIG_PROTECT="/etc /usr/kde/3.5/env /usr/kde/3.5/share/config /usr/kde/3.5/shutdown /usr/share/X11/xkb /usr/share/config"
CONFIG_PROTECT_MASK="/etc/env.d /etc/env.d/java/ /etc/gconf /etc/revdep-rebuild /etc/terminfo /etc/texmf/web2c"
CXXFLAGS="-march=nocona -O2 -pipe -fomit-frame-pointer"



Problem Description:
Unable to burn DVD.
There was one CD I could burn and one DVD with just 367MB.

Here you can some output from dmesg and K3B:
http://paste.olausson.de/d9fb377a51.html

Aug 21 20:56:36 freax ata5.00: 16 bytes trailing data
Aug 21 20:56:36 freax cdrom: This disc doesn't have any tracks I recognize!
Aug 21 20:58:34 freax ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
Aug 21 20:58:34 freax ata5.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0xad data 4 in
Aug 21 20:58:34 freax res 40/00:02:00:08:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
Aug 21 20:58:37 freax ata5: soft resetting port
Aug 21 20:58:37 freax ata5.00: configured for UDMA/66
Aug 21 20:58:37 freax ata5.01: configured for UDMA/33
Aug 21 20:58:37 freax ata5: EH complete
Aug 21 20:58:37 freax ata5.00: 16 bytes trailing data



Steps to reproduce:
Just try to burn a DVD


Thanks and regards
Bjoern
Comment 1 Tejun Heo 2007-08-21 18:18:59 UTC
Please attach full kernel boot log and the result of 'hdparm -i /dev/sr0'.  Also, you're using 80-c cable, right?
Comment 2 Bjoern Olausson 2007-08-22 04:46:44 UTC
May I pinpoint you to an earlyer bug I reportet:
Commnt by me: http://bugzilla.kernel.org/show_bug.cgi?id=8627#c6
Comment by Alber Lee: http://bugzilla.kernel.org/show_bug.cgi?id=8627#c16

Now there is this error again and I cant burn DVDs at all.


Here's the requested information:

Yes I am using a full blown UDM-100+ capable cable.
And IMHO it is not damaged.

hdparm -i /dev/sr0

/dev/sr0:
 
Model=PLEXTOR DVDR  PX-760A                  , FwRev=1.06    , SerialNo=              235***
Config={ Fixed Removeable DTR<=5Mbs DTR>10Mbs nonMagnetic }
RawCHS=0/0/0, TrkSize=0, SectSize=0, ECCbytes=0
BuffType=unknown, BuffSize=0kB, MaxMultSect=0
(maybe): CurCHS=0/0/0, CurSects=0, LBA=yes, LBAsects=0
IORDY=on/off, tPIO={min:120,w/IORDY:120}, tDMA={min:120,rec:120}
PIO modes:  pio0 pio1 pio2 pio3 pio4 
DMA modes:  mdma0 mdma1 mdma2 
UDMA modes: udma0 udma1 udma2 udma3 *udma4 
AdvancedPM=no
Drive conforms to: Unspecified:  ATA/ATAPI-3,4,5,6
 
* signifies the current active mode


hdparm -i /dev/sr1

/dev/sr1:

 Model=PLEXTOR DVD-ROM PX-130A                 , FwRev=1.03    , SerialNo=
 Config={ Fixed Removeable DTR<=5Mbs DTR>10Mbs nonMagnetic }
 RawCHS=0/0/0, TrkSize=0, SectSize=0, ECCbytes=0
 BuffType=13395, BuffSize=64kB, MaxMultSect=0
 (maybe): CurCHS=0/0/0, CurSects=0, LBA=yes, LBAsects=0
 IORDY=on/off, tPIO={min:120,w/IORDY:120}, tDMA={min:120,rec:120}
 PIO modes:  pio0 pio1 pio2 pio3 pio4
 DMA modes:  mdma0 mdma1 mdma2
 UDMA modes: udma0 udma1 *udma2 udma3 udma4 udma5
 AdvancedPM=no

 * signifies the current active mode


I tryed burning a DVD again and the result is on the bottom of the complete dmesg output... Again DVD burning faild.

Linux version 2.6.22.4 (root@freax) (gcc version 4.1.2 (Gentoo 4.1.2)) #2 SMP PREEMPT Tue Aug 21 23:50:57 CEST 2007
Command line: irqpoll root=/dev/sda3 video=nvidiafb:1280x1024-32@85,mtrr,ywrap console=tty0
BIOS-provided physical RAM map:
BIOS-e820: 0000000000000000 - 000000000009fc00 (usable)
BIOS-e820: 000000000009fc00 - 00000000000a0000 (reserved)
BIOS-e820: 00000000000e4000 - 0000000000100000 (reserved)
BIOS-e820: 0000000000100000 - 000000007ff80000 (usable)
BIOS-e820: 000000007ff80000 - 000000007ff8e000 (ACPI data)
BIOS-e820: 000000007ff8e000 - 000000007ffe0000 (ACPI NVS)
BIOS-e820: 000000007ffe0000 - 0000000080000000 (reserved)
BIOS-e820: 00000000ffb00000 - 0000000100000000 (reserved)
Entering add_active_range(0, 0, 159) 0 entries of 3200 used
Entering add_active_range(0, 256, 524160) 1 entries of 3200 used
end_pfn_map = 1048576
DMI 2.4 present.
ACPI: RSDP 000FAF20, 0024 (r2 ACPIAM)
ACPI: XSDT 7FF80100, 004C (r1 A_M_I_ OEMXSDT  7000724 MSFT      97)
ACPI: FACP 7FF80290, 00F4 (r3 A_M_I_ OEMFACP  7000724 MSFT      97)
ACPI: DSDT 7FF80590, 9560 (r1  A0543 A0543000        0 INTL 20060113)
ACPI: FACS 7FF8E000, 0040
ACPI: APIC 7FF80390, 0080 (r1 A_M_I_ OEMAPIC  7000724 MSFT      97)
ACPI: OEMB 7FF8E040, 0066 (r1 A_M_I_ AMI_OEM  7000724 MSFT      97)
ACPI: HPET 7FF89AF0, 0038 (r1 A_M_I_ OEMHPET  7000724 MSFT      97)
ACPI: MCFG 7FF89B30, 003C (r1 A_M_I_ OEMMCFG  7000724 MSFT      97)
No NUMA configuration found
Faking a node at 0000000000000000-000000007ff80000
Entering add_active_range(0, 0, 159) 0 entries of 3200 used
Entering add_active_range(0, 256, 524160) 1 entries of 3200 used
Bootmem setup node 0 0000000000000000-000000007ff80000
Zone PFN ranges:
  DMA            0 ->    4096
  DMA32        4096 ->  1048576
  Normal    1048576 ->  1048576
early_node_map[2] active PFN ranges
    0:        0 ->      159
    0:      256 ->  524160
On node 0 totalpages: 524063
  DMA zone: 88 pages used for memmap
  DMA zone: 2819 pages reserved
  DMA zone: 1092 pages, LIFO batch:0
  DMA32 zone: 11173 pages used for memmap
  DMA32 zone: 508891 pages, LIFO batch:31
  Normal zone: 0 pages used for memmap
ACPI: PM-Timer IO Port: 0x808
ACPI: Local APIC address 0xfee00000
ACPI: LAPIC (acpi_id[0x01] lapic_id[0x00] enabled)
Processor #0 (Bootup-CPU)
ACPI: LAPIC (acpi_id[0x02] lapic_id[0x01] enabled)
Processor #1
ACPI: LAPIC (acpi_id[0x03] lapic_id[0x82] disabled)
ACPI: LAPIC (acpi_id[0x04] lapic_id[0x83] disabled)
ACPI: IOAPIC (id[0x02] address[0xfec00000] gsi_base[0])
IOAPIC[0]: apic_id 2, address 0xfec00000, GSI 0-23
ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
ACPI: IRQ0 used by override.
ACPI: IRQ2 used by override.
ACPI: IRQ9 used by override.
Setting APIC routing to flat
ACPI: HPET id: 0x8086a201 base: 0xfed00000
Using ACPI (MADT) for SMP configuration information
swsusp: Registered nosave memory region: 000000000009f000 - 00000000000a0000
swsusp: Registered nosave memory region: 00000000000a0000 - 00000000000e4000
swsusp: Registered nosave memory region: 00000000000e4000 - 0000000000100000
Allocating PCI resources starting at 88000000 (gap: 80000000:7fb00000)
SMP: Allowing 4 CPUs, 2 hotplug CPUs
PERCPU: Allocating 37872 bytes of per cpu data
Built 1 zonelists.  Total pages: 509983
Kernel command line: irqpoll root=/dev/sda3 video=nvidiafb:1280x1024-32@85,mtrr,ywrap console=tty0
Misrouted IRQ fixup and polling support enabled
This may significantly impact system performance
Initializing CPU#0
PID hash table entries: 4096 (order: 12, 32768 bytes)
time.c: Detected 2404.110 MHz processor.
Console: colour VGA+ 80x25
Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
... MAX_LOCKDEP_SUBCLASSES:    8
... MAX_LOCK_DEPTH:          30
... MAX_LOCKDEP_KEYS:        2048
... CLASSHASH_SIZE:          1024
... MAX_LOCKDEP_ENTRIES:    8192
... MAX_LOCKDEP_CHAINS:      16384
... CHAINHASH_SIZE:          8192
memory used by lock dependency info: 1648 kB
per task-struct memory footprint: 1680 bytes
Checking aperture...
Memory: 2039564k/2096640k available (3898k kernel code, 56688k reserved, 2239k data, 364k init)
Calibrating delay using timer specific routine.. 4986.72 BogoMIPS (lpj=2493361)
Dentry cache hash table entries: 262144 (order: 9, 2097152 bytes)
Inode-cache hash table entries: 131072 (order: 8, 1048576 bytes)
Mount-cache hash table entries: 256
CPU: L1 I cache: 32K, L1 D cache: 32K
CPU: L2 cache: 4096K
CPU 0/0 -> Node 0
using mwait in idle threads.
CPU: Physical Processor ID: 0
CPU: Processor Core ID: 0
CPU0: Thermal monitoring enabled (TM2)
lockdep: not fixing up alternatives.
ACPI: Core revision 20070126
Using local APIC timer interrupts.
result 16695208
Detected 16.695 MHz APIC timer.
lockdep: not fixing up alternatives.
Booting processor 1/2 APIC 0x1
Initializing CPU#1
Calibrating delay using timer specific routine.. 4808.36 BogoMIPS (lpj=2404181)
CPU: L1 I cache: 32K, L1 D cache: 32K
CPU: L2 cache: 4096K
CPU 1/1 -> Node 0
CPU: Physical Processor ID: 0
CPU: Processor Core ID: 1
CPU1: Thermal monitoring enabled (TM2)
Intel(R) Core(TM)2 CPU          6600  @ 2.40GHz stepping 06
checking TSC synchronization [CPU#0 -> CPU#1]: passed.
Brought up 2 CPUs
migration_cost=20
NET: Registered protocol family 16
ACPI: bus type pci registered
PCI: BIOS Bug: MCFG area at f0000000 is not E820-reserved
PCI: Not using MMCONFIG.
PCI: Using configuration type 1
ACPI: Interpreter enabled
ACPI: (supports S0 S1 S3 S4 S5)
ACPI: Using IOAPIC for interrupt routing
ACPI: PCI Root Bridge [PCI0] (0000:00)
PCI: Probing PCI hardware (bus 00)
PCI quirk: region 0800-087f claimed by ICH6 ACPI/GPIO/TCO
PCI quirk: region 0480-04bf claimed by ICH6 GPIO
PCI: Transparent bridge - 0000:00:1e.0
ACPI: PCI Interrupt Routing Table [\\_SB_.PCI0._PRT]
ACPI: PCI Interrupt Routing Table [\\_SB_.PCI0.P0P1._PRT]
ACPI: PCI Interrupt Routing Table [\\_SB_.PCI0.P0P3._PRT]
ACPI: PCI Interrupt Routing Table [\\_SB_.PCI0.P0P4._PRT]
ACPI: PCI Interrupt Routing Table [\\_SB_.PCI0.P0P7._PRT]
ACPI: PCI Interrupt Link [LNKA] (IRQs 3 4 5 6 7 10 *11 12 14 15)
ACPI: PCI Interrupt Link [LNKB] (IRQs 3 4 5 6 *7 10 11 12 14 15)
ACPI: PCI Interrupt Link [LNKC] (IRQs *3 4 5 6 7 10 11 12 14 15)
ACPI: PCI Interrupt Link [LNKD] (IRQs 3 4 5 6 7 *10 11 12 14 15)
ACPI: PCI Interrupt Link [LNKE] (IRQs 3 4 *5 6 7 10 11 12 14 15)
ACPI: PCI Interrupt Link [LNKF] (IRQs 3 4 5 6 7 *10 11 12 14 15)
ACPI: PCI Interrupt Link [LNKG] (IRQs 3 4 5 6 7 10 *11 12 14 15)
ACPI: PCI Interrupt Link [LNKH] (IRQs 3 4 5 *6 7 10 11 12 14 15)
Linux Plug and Play Support v0.97 (c) Adam Belay
pnp: PnP ACPI init
ACPI: bus type pnp registered
pnp: PnP ACPI: found 13 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
NET: Registered protocol family 23
Bluetooth: Core ver 2.11
NET: Registered protocol family 31
Bluetooth: HCI device and connection manager initialized
Bluetooth: HCI socket layer initialized
PCI-GART: No AMD northbridge found.
hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
hpet0: 3 64-bit timers, 14318180 Hz
pnp: 00:01: iomem range 0xfed13000-0xfed19fff has been reserved
pnp: 00:06: ioport range 0x290-0x297 has been reserved
pnp: 00:07: iomem range 0xfed1c000-0xfed1ffff has been reserved
pnp: 00:07: iomem range 0xfed20000-0xfed3ffff has been reserved
pnp: 00:07: iomem range 0xfed50000-0xfed8ffff has been reserved
pnp: 00:07: iomem range 0xffb00000-0xffbfffff could not be reserved
Time: tsc clocksource has been installed.
pnp: 00:09: iomem range 0xfec00000-0xfec00fff has been reserved
pnp: 00:09: iomem range 0xfee00000-0xfee00fff could not be reserved
pnp: 00:0b: iomem range 0xf0000000-0xf3ffffff has been reserved
pnp: 00:0c: iomem range 0x0-0x9ffff could not be reserved
pnp: 00:0c: iomem range 0xc0000-0xdffff has been reserved
pnp: 00:0c: iomem range 0xe0000-0xfffff could not be reserved
pnp: 00:0c: iomem range 0x100000-0x7fffffff could not be reserved
ACPI: PCI Interrupt 0000:01:03.0[A] -> GSI 21 (level, low) -> IRQ 21
ohci1394: fw-host0: OHCI-1394 1.1 (PCI): IRQ=[21]  MMIO=[ebcef800-ebceffff]  Max Packet=[2048]  IR/IT contexts=[4/8]
PCI: Bridge: 0000:00:01.0
  IO window: c000-cfff
  MEM window: ebe00000-efefffff
  PREFETCH window: c3700000-e36fffff
PCI: Bridge: 0000:00:1c.0
  IO window: disabled.
  MEM window: disabled.
  PREFETCH window: c3600000-c36fffff
PCI: Bridge: 0000:00:1c.3
  IO window: b000-bfff
  MEM window: ebd00000-ebdfffff
  PREFETCH window: disabled.
PCI: Bridge: 0000:00:1e.0
  IO window: a000-afff
  MEM window: e3800000-ebcfffff
  PREFETCH window: c3500000-c35fffff
ACPI: PCI Interrupt 0000:00:01.0[A] -> GSI 16 (level, low) -> IRQ 16
PCI: Setting latency timer of device 0000:00:01.0 to 64
ACPI: PCI Interrupt 0000:00:1c.0[A] -> GSI 16 (level, low) -> IRQ 16
PCI: Setting latency timer of device 0000:00:1c.0 to 64
ACPI: PCI Interrupt 0000:00:1c.3[D] -> GSI 19 (level, low) -> IRQ 19
PCI: Setting latency timer of device 0000:00:1c.3 to 64
PCI: Setting latency timer of device 0000:00:1e.0 to 64
NET: Registered protocol family 2
IP route cache hash table entries: 65536 (order: 7, 524288 bytes)
TCP established hash table entries: 262144 (order: 12, 16777216 bytes)
TCP bind hash table entries: 65536 (order: 9, 3670016 bytes)
TCP: Hash tables configured (established 262144 bind 65536)
TCP reno registered
IA-32 Microcode Update Driver: v1.14a <tigran@aivazian.fsnet.co.uk>
Total HugeTLB memory allocated, 0
Coda Kernel/Venus communications, v6.0.0, coda@cs.cmu.edu
Installing knfsd (copyright (C) 1996 okir@monad.swb.de).
NTFS driver 2.1.28 [Flags: R/W].
io scheduler noop registered
io scheduler deadline registered
io scheduler cfq registered (default)
Boot video device is 0000:04:00.0
PCI: Setting latency timer of device 0000:00:01.0 to 64
assign_interrupt_mode Found MSI capability
Allocate Port Service[0000:00:01.0:pcie00]
PCI: Setting latency timer of device 0000:00:1c.0 to 64
assign_interrupt_mode Found MSI capability
Allocate Port Service[0000:00:1c.0:pcie00]
Allocate Port Service[0000:00:1c.0:pcie02]
PCI: Setting latency timer of device 0000:00:1c.3 to 64
assign_interrupt_mode Found MSI capability
Allocate Port Service[0000:00:1c.3:pcie00]
input: Power Button (FF) as /class/input/input0
ACPI: Power Button (FF) [PWRF]
input: Power Button (CM) as /class/input/input1
ACPI: Power Button (CM) [PWRB]
ACPI: Processor [CPU1] (supports 8 throttling states)
ACPI: Processor [CPU2] (supports 8 throttling states)
ACPI Exception (processor_core-0781): AE_NOT_FOUND, Processor Device is not present [20070126]
ACPI Exception (processor_core-0781): AE_NOT_FOUND, Processor Device is not present [20070126]
Real Time Clock Driver v1.12ac
hpet_resources: 0xfed00000 is busy
intel_rng: FWH not detected
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
ieee1394: Host added: ID:BUS[0-00:1023]  GUID[0011d80000eaf58e]
floppy0: no floppy controllers found
RAMDISK driver initialized: 16 RAM disks of 4096K size 1024 blocksize
loop: module loaded
tun: Universal TUN/TAP device driver, 1.6
tun: (C) 1999-2004 Max Krasnyansky <maxk@qualcomm.com>
usbcore: registered new interface driver irda-usb
USB IrDA support registered
usbcore: registered new interface driver stir4200
usbcore: registered new interface driver mcs7780
ahci 0000:00:1f.2: version 2.2
ACPI: PCI Interrupt 0000:00:1f.2[B] -> GSI 23 (level, low) -> IRQ 23
ahci 0000:00:1f.2: AHCI 0001.0100 32 slots 4 ports 3 Gbps 0xf impl SATA mode
ahci 0000:00:1f.2: flags: 64bit ncq led clo pio slum part 
PCI: Setting latency timer of device 0000:00:1f.2 to 64
scsi0 : ahci
scsi1 : ahci
scsi2 : ahci
scsi3 : ahci
ata1: SATA max UDMA/133 cmd 0xffffc20001738900 ctl 0x0000000000000000 bmdma 0x0000000000000000 irq 1276
ata2: SATA max UDMA/133 cmd 0xffffc20001738980 ctl 0x0000000000000000 bmdma 0x0000000000000000 irq 1276
ata3: SATA max UDMA/133 cmd 0xffffc20001738a00 ctl 0x0000000000000000 bmdma 0x0000000000000000 irq 1276
ata4: SATA max UDMA/133 cmd 0xffffc20001738a80 ctl 0x0000000000000000 bmdma 0x0000000000000000 irq 1276
ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
ata1.00: ATA-7: WDC WD740ADFD-00NLR1, 20.07P20, max UDMA/133
ata1.00: 145226112 sectors, multi 16: LBA48 NCQ (not used)
ata1.00: configured for UDMA/133
ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
ata2.00: ATA-6: External Disk 0, RGL10364, max UDMA/133
ata2.00: 145226112 sectors, multi 1: LBA48 
ata2.00: configured for UDMA/133
ata3: SATA link down (SStatus 0 SControl 300)
ata4: SATA link down (SStatus 0 SControl 300)
scsi 0:0:0:0: Direct-Access    ATA      WDC WD740ADFD-00 20.0 PQ: 0 ANSI: 5
sd 0:0:0:0: [sda] 145226112 512-byte hardware sectors (74356 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] 145226112 512-byte hardware sectors (74356 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: sda1 sda2 sda3
sd 0:0:0:0: [sda] Attached SCSI disk
sd 0:0:0:0: Attached scsi generic sg0 type 0
scsi 1:0:0:0: Direct-Access    ATA      External Disk 0  RGL1 PQ: 0 ANSI: 5
sd 1:0:0:0: [sdb] 145226112 512-byte hardware sectors (74356 MB)
sd 1:0:0:0: [sdb] Write Protect is off
sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn\'t support DPO or FUA
sd 1:0:0:0: [sdb] 145226112 512-byte hardware sectors (74356 MB)
sd 1:0:0:0: [sdb] Write Protect is off
sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn\'t support DPO or FUA
sdb: sdb1
sd 1:0:0:0: [sdb] Attached SCSI disk
sd 1:0:0:0: Attached scsi generic sg1 type 0
ata_piix 0000:00:1f.1: version 2.11
ACPI: PCI Interrupt 0000:00:1f.1[A] -> GSI 22 (level, low) -> IRQ 22
PCI: Setting latency timer of device 0000:00:1f.1 to 64
scsi4 : ata_piix
scsi5 : ata_piix
ata5: PATA max UDMA/133 cmd 0x00000000000101f0 ctl 0x00000000000103f6 bmdma 0x000000000001ffa0 irq 14
ata6: PATA max UDMA/133 cmd 0x0000000000010170 ctl 0x0000000000010376 bmdma 0x000000000001ffa8 irq 15
ata5.00: ATAPI: PLEXTOR DVDR  PX-760A, 1.06, max UDMA/66
ata5.01: ATAPI: PLEXTOR DVD-ROM PX-130A, 1.03, max UDMA/100
ata5.01: limited to UDMA/33 due to 40-wire cable
ata5.00: configured for UDMA/66
ata5.01: configured for UDMA/33
scsi 4:0:0:0: CD-ROM            PLEXTOR  DVDR  PX-760A  1.06 PQ: 0 ANSI: 5
sr0: scsi3-mmc drive: 94x/94x writer cd/rw xa/form2 cdda tray
Uniform CD-ROM driver Revision: 3.20
sr 4:0:0:0: Attached scsi CD-ROM sr0
sr 4:0:0:0: Attached scsi generic sg2 type 5
scsi 4:0:1:0: CD-ROM            PLEXTOR  DVD-ROM PX-130A  1.03 PQ: 0 ANSI: 5
sr1: scsi3-mmc drive: 0x/50x cd/rw xa/form2 cdda tray
sr 4:0:1:0: Attached scsi CD-ROM sr1
sr 4:0:1:0: Attached scsi generic sg3 type 5
I2O subsystem v1.325
i2o: max drivers = 8
Fusion MPT base driver 3.04.04
Copyright (c) 1999-2007 LSI Logic Corporation
Fusion MPT SPI Host driver 3.04.04
Fusion MPT SAS Host driver 3.04.04
ieee1394: raw1394: /dev/raw1394 device initialized
ACPI: PCI Interrupt 0000:00:1d.7[A] -> GSI 20 (level, low) -> IRQ 20
PCI: Setting latency timer of device 0000:00:1d.7 to 64
ehci_hcd 0000:00:1d.7: EHCI Host Controller
ehci_hcd 0000:00:1d.7: new USB bus registered, assigned bus number 1
ehci_hcd 0000:00:1d.7: debug port 1
PCI: cache line size of 32 is not supported by device 0000:00:1d.7
ehci_hcd 0000:00:1d.7: irq 20, io mem 0xefffbc00
ehci_hcd 0000:00:1d.7: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004
usb usb1: configuration #1 chosen from 1 choice
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 8 ports detected
ohci_hcd: 2006 August 04 USB 1.1 \'Open\' Host Controller (OHCI) Driver
USB Universal Host Controller Interface driver v3.0
ACPI: PCI Interrupt 0000:00:1d.0[A] -> GSI 20 (level, low) -> IRQ 20
PCI: Setting latency timer of device 0000:00:1d.0 to 64
uhci_hcd 0000:00:1d.0: UHCI Host Controller
uhci_hcd 0000:00:1d.0: new USB bus registered, assigned bus number 2
uhci_hcd 0000:00:1d.0: irq 20, io base 0x0000e480
usb usb2: configuration #1 chosen from 1 choice
hub 2-0:1.0: USB hub found
hub 2-0:1.0: 2 ports detected
ACPI: PCI Interrupt 0000:00:1d.1[B] -> GSI 17 (level, low) -> IRQ 17
PCI: Setting latency timer of device 0000:00:1d.1 to 64
uhci_hcd 0000:00:1d.1: UHCI Host Controller
uhci_hcd 0000:00:1d.1: new USB bus registered, assigned bus number 3
uhci_hcd 0000:00:1d.1: irq 17, io base 0x0000e800
usb usb3: configuration #1 chosen from 1 choice
hub 3-0:1.0: USB hub found
hub 3-0:1.0: 2 ports detected
ACPI: PCI Interrupt 0000:00:1d.2[C] -> GSI 18 (level, low) -> IRQ 18
PCI: Setting latency timer of device 0000:00:1d.2 to 64
uhci_hcd 0000:00:1d.2: UHCI Host Controller
uhci_hcd 0000:00:1d.2: new USB bus registered, assigned bus number 4
uhci_hcd 0000:00:1d.2: irq 18, io base 0x0000e880
usb usb4: configuration #1 chosen from 1 choice
usb 1-1: new high speed USB device using ehci_hcd and address 2
hub 4-0:1.0: USB hub found
hub 4-0:1.0: 2 ports detected
ACPI: PCI Interrupt 0000:00:1d.3[D] -> GSI 19 (level, low) -> IRQ 19
PCI: Setting latency timer of device 0000:00:1d.3 to 64
uhci_hcd 0000:00:1d.3: UHCI Host Controller
uhci_hcd 0000:00:1d.3: new USB bus registered, assigned bus number 5
uhci_hcd 0000:00:1d.3: irq 19, io base 0x0000ec00
usb usb5: configuration #1 chosen from 1 choice
hub 5-0:1.0: USB hub found
hub 5-0:1.0: 2 ports detected
usb 1-1: configuration #1 chosen from 1 choice
hub 1-1:1.0: USB hub found
hub 1-1:1.0: 4 ports detected
usb 1-7: new high speed USB device using ehci_hcd and address 7
usb 1-7: configuration #1 chosen from 1 choice
hub 1-7:1.0: USB hub found
hub 1-7:1.0: 4 ports detected
usb 2-2: new low speed USB device using uhci_hcd and address 2
usb 2-2: configuration #1 chosen from 1 choice
usb 3-1: new low speed USB device using uhci_hcd and address 2
usb 3-1: configuration #1 chosen from 1 choice
usb 3-2: new full speed USB device using uhci_hcd and address 3
usb 3-2: configuration #1 chosen from 1 choice
hub 3-2:1.0: USB hub found
hub 3-2:1.0: 3 ports detected
usb 4-1: new full speed USB device using uhci_hcd and address 2
usb 4-1: configuration #1 chosen from 1 choice
usb 1-1.1: new full speed USB device using ehci_hcd and address 8
usb 1-1.1: configuration #1 chosen from 1 choice
usb 1-1.2: new high speed USB device using ehci_hcd and address 9
usb 1-1.2: configuration #1 chosen from 1 choice
usb 1-1.3: new full speed USB device using ehci_hcd and address 10
usb 1-1.3: configuration #1 chosen from 1 choice
usb 1-7.1: new high speed USB device using ehci_hcd and address 11
usb 1-7.1: configuration #1 chosen from 1 choice
hub 1-7.1:1.0: USB hub found
hub 1-7.1:1.0: 4 ports detected
usb 1-7.2: new high speed USB device using ehci_hcd and address 12
usb 1-7.2: configuration #1 chosen from 1 choice
usb 1-7.3: new high speed USB device using ehci_hcd and address 13
usb 1-7.3: configuration #1 chosen from 1 choice
usb 3-2.2: new full speed USB device using uhci_hcd and address 4
usb 3-2.2: configuration #1 chosen from 1 choice
usb 3-2.3: new full speed USB device using uhci_hcd and address 5
usb 3-2.3: configuration #1 chosen from 1 choice
drivers/usb/class/usblp.c: usblp0: USB Bidirectional printer dev 9 if 0 alt 0 proto 2 vid 0x04A9 pid 0x10A5
usbcore: registered new interface driver usblp
drivers/usb/class/usblp.c: v0.13: USB Printer Device Class driver
Initializing USB Mass Storage driver...
scsi6 : SCSI emulation for USB Mass Storage devices
usb-storage: device found at 12
usb-storage: waiting for device to settle before scanning
usbcore: registered new interface driver usb-storage
USB Mass Storage support registered.
usbcore: registered new interface driver usbserial
drivers/usb/serial/usb-serial.c: USB Serial support registered for generic
usbcore: registered new interface driver usbserial_generic
drivers/usb/serial/usb-serial.c: USB Serial Driver core
drivers/usb/serial/usb-serial.c: USB Serial support registered for Handspring Visor / Palm OS
drivers/usb/serial/usb-serial.c: USB Serial support registered for Sony Clie 3.5
drivers/usb/serial/usb-serial.c: USB Serial support registered for Sony Clie 5.0
usbcore: registered new interface driver visor
drivers/usb/serial/visor.c: USB HandSpring Visor / Palm OS driver
PNP: No PS/2 controller found. Probing ports directly.
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
i2c /dev entries driver
ACPI: PCI Interrupt 0000:00:1f.3[B] -> GSI 23 (level, low) -> IRQ 23
coretemp coretemp.0: Using undocumented features, absolute temperature might be wrong!
coretemp coretemp.1: Using undocumented features, absolute temperature might be wrong!
device-mapper: ioctl: 4.11.0-ioctl (2006-10-12) initialised: dm-devel@redhat.com
Bluetooth: HCI USB driver ver 2.9
usbcore: registered new interface driver hci_usb
Bluetooth: Virtual HCI driver ver 1.2
Bluetooth: HCI UART driver ver 2.2
Bluetooth: HCI H4 protocol initialized
Bluetooth: HCI BCSP protocol initialized
Bluetooth: Broadcom Blutonium firmware driver ver 1.1
usbcore: registered new interface driver bcm203x
Bluetooth: Digianswer Bluetooth USB driver ver 0.8
usbcore: registered new interface driver bpa10x
Bluetooth: BlueFRITZ! USB driver ver 1.1
usbcore: registered new interface driver bfusb
usbcore: registered new interface driver hiddev
input: Logitech USB RECEIVER as /class/input/input2
input: USB HID v1.11 Mouse [Logitech USB RECEIVER] on usb-0000:00:1d.0-2
hiddev96: USB HID v1.10 Device [T-wins ASUS DH Remote] on usb-0000:00:1d.1-1
input: Logitech USB Receiver as /class/input/input3
input: USB HID v1.11 Mouse [Logitech USB Receiver] on usb-0000:00:1d.7-1.1
input: Logitech USB Receiver as /class/input/input4
input,hiddev97: USB HID v1.11 Device [Logitech USB Receiver] on usb-0000:00:1d.7-1.1
input: Logitech Logitech BT Mini-Receiver as /class/input/input5
input: USB HID v1.11 Keyboard [Logitech Logitech BT Mini-Receiver] on usb-0000:00:1d.1-2.2
input: Logitech Logitech BT Mini-Receiver as /class/input/input6
input,hiddev98: USB HID v1.11 Mouse [Logitech Logitech BT Mini-Receiver] on usb-0000:00:1d.1-2.3
usbcore: registered new interface driver usbhid
drivers/hid/usbhid/hid-core.c: v2.6:USB HID core driver
oprofile: using NMI interrupt.
TCP cubic registered
NET: Registered protocol family 1
NET: Registered protocol family 10
IPv6 over IPv4 tunneling driver
NET: Registered protocol family 17
IrCOMM protocol (Dag Brattli)
Bluetooth: L2CAP ver 2.8
Bluetooth: L2CAP socket layer initialized
Bluetooth: SCO (Voice Link) ver 0.5
Bluetooth: SCO socket layer initialized
Bluetooth: RFCOMM socket layer initialized
Bluetooth: RFCOMM TTY layer initialized
Bluetooth: RFCOMM ver 1.8
Bluetooth: BNEP (Ethernet Emulation) ver 1.2
Bluetooth: BNEP filters: protocol multicast
Bluetooth: HIDP (Human Interface Emulation) ver 1.2
NET: Registered protocol family 33
RxRPC: Registered security type 2 \'rxkad\'
ieee80211: 802.11 data/management/control stack, git-1.1.13
ieee80211: Copyright (C) 2004-2005 Intel Corporation <jketreno@linux.intel.com>
ieee80211_crypt: registered algorithm \'NULL\'
ieee80211_crypt: registered algorithm \'WEP\'
ieee80211_crypt: registered algorithm \'CCMP\'
ieee80211_crypt: registered algorithm \'TKIP\'
drivers/rtc/hctosys.c: unable to open rtc device (rtc0)
kjournald starting.  Commit interval 5 seconds
EXT3-fs: mounted filesystem with ordered data mode.
VFS: Mounted root (ext3 filesystem) readonly.
Freeing unused kernel memory: 364k freed
ACPI: PCI Interrupt 0000:02:00.0[A] -> GSI 19 (level, low) -> IRQ 19
PCI: Setting latency timer of device 0000:02:00.0 to 64
sky2 0000:02:00.0: v1.14 addr 0xebdfc000 irq 19 Yukon-EC (0xb6) rev 2
sky2 eth0: addr 00:18:f3:84:4f:8a
ACPI: PCI Interrupt 0000:00:1b.0[A] -> GSI 19 (level, low) -> IRQ 19
PCI: Setting latency timer of device 0000:00:1b.0 to 64
EXT3 FS on sda3, internal journal
scsi 6:0:0:0: Direct-Access    Generic  STORAGE DEVICE  9601 PQ: 0 ANSI: 0
sd 6:0:0:0: [sdc] Attached SCSI removable disk
sd 6:0:0:0: Attached scsi generic sg4 type 0
scsi 6:0:0:1: Direct-Access    Generic  STORAGE DEVICE  9601 PQ: 0 ANSI: 0
sd 6:0:0:1: [sdd] Attached SCSI removable disk
sd 6:0:0:1: Attached scsi generic sg5 type 0
scsi 6:0:0:2: Direct-Access    Generic  STORAGE DEVICE  9601 PQ: 0 ANSI: 0
sd 6:0:0:2: [sde] Attached SCSI removable disk
sd 6:0:0:2: Attached scsi generic sg6 type 0
scsi 6:0:0:3: Direct-Access    Generic  STORAGE DEVICE  9601 PQ: 0 ANSI: 0
sd 6:0:0:3: [sdf] Attached SCSI removable disk
sd 6:0:0:3: Attached scsi generic sg7 type 0
usb-storage: device scan complete
ath_hal: module license \'Proprietary\' taints kernel.
ath_hal: 0.9.18.0 (AR5210, AR5211, AR5212, RF5111, RF5112, RF2413, RF5413)
wlan: 0.8.4.2 (0.9.3.2)
ath_pci: no version for \"ieee80211_encap\" found: kernel tainted.
ath_pci: 0.9.4.5 (0.9.3.2)
ACPI: PCI Interrupt 0000:01:02.0[A] -> GSI 23 (level, low) -> IRQ 23
ath_rate_sample: 1.2 (0.9.3.2)
wifi0: 11b rates: 1Mbps 2Mbps 5.5Mbps 11Mbps
wifi0: 11g rates: 1Mbps 2Mbps 5.5Mbps 11Mbps 6Mbps 9Mbps 12Mbps 18Mbps 24Mbps 36Mbps 48Mbps 54Mbps
wifi0: turboG rates: 6Mbps 12Mbps 18Mbps 24Mbps 36Mbps 48Mbps 54Mbps
wifi0: H/W encryption support: WEP AES AES_CCM TKIP
wifi0: mac 7.9 phy 4.5 radio 5.6
wifi0: Use hw queue 1 for WME_AC_BE traffic
wifi0: Use hw queue 0 for WME_AC_BK traffic
wifi0: Use hw queue 2 for WME_AC_VI traffic
wifi0: Use hw queue 3 for WME_AC_VO traffic
wifi0: Use hw queue 8 for CAB traffic
wifi0: Use hw queue 9 for beacons
wifi0: Atheros 5212: mem=0xebcf0000, irq=23
ath_rate_amrr: 0.1 (0.9.3.2)
ath_rate_onoe: 1.0 (0.9.3.2)
wlan: mac acl policy registered
Linux video capture interface: v2.00
bttv: driver version 0.9.17 loaded
bttv: using 8 buffers with 2080k (520 pages) each for capture
bttv: Bt8xx card found (0).
ACPI: PCI Interrupt 0000:01:01.0[A] -> GSI 22 (level, low) -> IRQ 22
bttv0: Bt878 (rev 17) at 0000:01:01.0, irq: 22, latency: 64, mmio: 0xc35fe000
bttv0: detected: Pinnacle PCTV [bswap] [card=39], PCI subsystem ID is bd11:1200
bttv0: using: Pinnacle PCTV Studio/Rave [card=39,autodetected]
bttv0: gpio: en=00000000, out=00000000 in=00ff33ff [init]
bttv0: i2c: checking for MSP34xx @ 0x80... not found
bttv0: miro: id=12 tuner=5 radio=no stereo=no
bttv0: using tuner=5
bttv0: i2c: checking for MSP34xx @ 0x80... not found
bttv0: i2c: checking for TDA9875 @ 0xb0... not found
bttv0: i2c: checking for TDA7432 @ 0x8a... not found
bttv0: i2c: checking for TDA9887 @ 0x86... not found
tuner 1-0060: All bytes are equal. It is not a TEA5767
tuner 1-0060: chip found @ 0xc0 (bt878 #0 [sw])
tuner 1-0060: type set to 5 (Philips PAL_BG (FI1216 and compatibles))
tuner 1-0060: type set to 5 (Philips PAL_BG (FI1216 and compatibles))
bttv0: registered device video0
bttv0: registered device vbi0
bttv0: PLL: 28636363 => 35468950 .. ok
drivers/usb/serial/usb-serial.c: USB Serial support registered for MCT U232
usbcore: registered new interface driver mct_u232
drivers/usb/serial/mct_u232.c: Magic Control Technology USB-RS232 converter driver z2.0
vboxdrv: Trying to deactivate NMI watchdog permanently...
vboxdrv: Successfully done.
Adding 979956k swap on /dev/sda2.  Priority:-1 extents:1 across:979956k
sky2 eth0: enabling interface
sky2 eth0: ram buffer 48K
ADDRCONF(NETDEV_UP): eth0: link is not ready
sky2 eth0: Link is up at 1000 Mbps, full duplex, flow control both
ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
ath0: no IPv6 routers present
eth0: no IPv6 routers present
cdrom: This disc doesn\'t have any tracks I recognize!
ata5.00: 16 bytes trailing data
ata5.00: 16 bytes trailing data
ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
ata5.00: cmd a0/01:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x2a data 32768 out
        res 40/00:03:00:00:20/00:00:00:00:00/b0 Emask 0x4 (timeout)
ata5: port is slow to respond, please be patient (Status 0xd8)
ata5: device not ready (errno=-16), forcing hardreset
ata5: soft resetting port
ata5.00: configured for UDMA/66
ata5.01: configured for UDMA/33
ata5: EH complete
ata5.00: 16 bytes trailing data


Thanks for the help
regards
Bjoern
Comment 3 Bjoern Olausson 2007-08-25 14:06:03 UTC
Okay, some more interesting stuff. I had to burn a DVD so i took a chance on booting a LinuxLive CD.

Burning a DVD was no problem using the Sabayon 1.0 BE LiveDVD. It uses 2.6.22-sabayon Kernel

sabayonx86 ~ # uname -a
Linux sabayonx86 2.6.22-sabayon #1 SMP Wed Jul 11 18:17:15 UTC 2007 i686 Intel(R) Core(TM)2 CPU 6600 @ 2.40GHz GenuineIntel GNU/Linux

full bootlog:
http://paste.olausson.de/e12c80f7f7.html

regards
Bjoern
Comment 4 Tejun Heo 2007-08-26 19:21:25 UTC
[cc'ing Albert].

Albert, would this be fixed by fixing media polling code?  Do we need trailing data draining?
Comment 5 Bjoern Olausson 2007-09-09 15:47:56 UTC
Still the same bug in vanilla-2.6.22.6 (with asus p5w-dh delux patch)

Burning impossible:

Sep 10 00:28:11 freax ata7.00: 16 bytes trailing data
Sep 10 00:28:36 freax ata7.00: 16 bytes trailing data
Sep 10 00:29:33 freax cdrom: This disc doesn't have any tracks I recognize!
Sep 10 00:29:33 freax ata7.00: 16 bytes trailing data
Sep 10 00:40:58 freax ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
Sep 10 00:40:58 freax ata7.00: cmd a0/01:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x2a data 3276      8 out
Sep 10 00:40:58 freax res 40/00:03:00:00:20/00:00:00:00:00/b0 Emask 0x4 (timeout)
Sep 10 00:41:03 freax ata7: port is slow to respond, please be patient (Status 0xd8)
Sep 10 00:41:08 freax ata7: device not ready (errno=-16), forcing hardreset
Sep 10 00:41:08 freax ata7: soft resetting port
Sep 10 00:41:09 freax ata7.00: configured for UDMA/66
Sep 10 00:41:09 freax ata7.01: configured for UDMA/33
Sep 10 00:41:09 freax ata7: EH complete
Sep 10 00:41:17 freax ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
Sep 10 00:41:17 freax ata7.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0xad data 4 in
Sep 10 00:41:17 freax res 40/00:02:00:08:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
Sep 10 00:41:17 freax ata7: soft resetting port
Sep 10 00:41:18 freax ata7.00: configured for UDMA/66
Sep 10 00:41:18 freax ata7.01: configured for UDMA/33
Sep 10 00:41:18 freax ata7: EH complete
Sep 10 00:41:18 freax ata7.00: 16 bytes trailing data
Comment 6 Bjoern Olausson 2007-09-11 11:05:31 UTC
As of 2.6.23-rc6 I am able to burn again.

But sill I do get this error after burning is complete:

Sep 11 19:40:30 freax ata7.00: 16 bytes trailing data
Sep 11 19:40:30 freax cdrom: This disc doesn't have any tracks I recognize!
Sep 11 19:40:30 freax ata7.00: 16 bytes trailing data
Sep 11 19:41:00 freax ata7.00: 16 bytes trailing data
Sep 11 19:48:37 freax ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
Sep 11 19:48:37 freax ata7.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0xad data 4 in
Sep 11 19:48:37 freax res 40/00:02:00:08:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
Sep 11 19:48:39 freax ata7: soft resetting port
Sep 11 19:48:39 freax ata7.00: configured for UDMA/66
Sep 11 19:48:39 freax ata7.01: configured for UDMA/33
Sep 11 19:48:39 freax ata7: EH complete
Sep 11 19:48:40 freax ata7.00: 16 bytes trailing data

Full log at:
http://paste.olausson.de/955bf74895.html

regards
Bjoern
Comment 7 Bjoern Olausson 2007-09-18 04:01:55 UTC
Bug is still present...

Tried burning a Dual-Layer DVD: got the following error:

cdrom: This disc doesn't have any tracks I recognize!
ata7.00: 16 bytes trailing data
ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
ata7.00: cmd a0/01:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x2a data 32768 out
         res 40/00:03:00:00:20/00:00:00:00:00/b0 Emask 0x4 (timeout)
ata7: port is slow to respond, please be patient (Status 0xd8)
ata7: device not ready (errno=-16), forcing hardreset
ata7: soft resetting port
ata7.00: configured for UDMA/66
ata7.01: configured for UDMA/33
ata7: EH complete
ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
ata7.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0xad data 4 in
         res 40/00:02:00:08:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
ata7: soft resetting port
ata7.00: configured for UDMA/66
ata7.01: configured for UDMA/33
ata7: EH complete
ata7.00: 16 bytes trailing data


:-[ WRITE@LBA=a6c60h failed with SK=0h/ASC=00h/ACQ=03h]: Input/output error
:-( write failed: Input/output error
Comment 8 Bjoern Olausson 2007-09-22 12:27:45 UTC
same in 2.6.23-rc7:

Sep 22 21:20:30 freax cdrom: This disc doesn't have any tracks I recognize!
Sep 22 21:20:36 freax ata7.00: 16 bytes trailing data
Sep 22 21:26:08 freax ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
Sep 22 21:26:08 freax ata7.00: cmd a0/01:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x2a data 32768 out
Sep 22 21:26:08 freax res 40/00:03:00:00:20/00:00:00:00:00/b0 Emask 0x4 (timeout)
Sep 22 21:26:13 freax ata7: port is slow to respond, please be patient (Status 0xd8)
Sep 22 21:26:18 freax ata7: device not ready (errno=-16), forcing hardreset
Sep 22 21:26:18 freax ata7: soft resetting port
Sep 22 21:26:19 freax ata7.00: configured for UDMA/66
Sep 22 21:26:19 freax ata7.01: configured for UDMA/33
Sep 22 21:26:19 freax ata7: EH complete
Sep 22 21:26:25 freax ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
Sep 22 21:26:25 freax ata7.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0xad data 4 in
Sep 22 21:26:25 freax res 40/00:02:00:08:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
Sep 22 21:26:25 freax ata7: soft resetting port
Sep 22 21:26:26 freax ata7.00: configured for UDMA/66
Sep 22 21:26:26 freax ata7.01: configured for UDMA/33
Sep 22 21:26:26 freax ata7: EH complete
Sep 22 21:26:26 freax ata7.00: 16 bytes trailing data
Comment 9 Albert Lee 2007-09-26 00:40:59 UTC
Hi Bjoern,

Could you try if Alan's "Set transfer sizes properly for ATAPI" patch helps?
(http://marc.info/?l=linux-ide&m=119029648803221&w=2)
Comment 10 Bjoern Olausson 2007-09-26 01:14:59 UTC
I'll check it and report in a few hours

Thanks
Bjoern
Comment 11 Bjoern Olausson 2007-09-26 02:03:04 UTC
Created attachment 12950 [details]
dvd.patch

root@freax $ patch -p0 < dvd.patch
patching file libata-scsi.c
Hunk #1 succeeded at 2273 (offset -3 lines).
Hunk #2 succeeded at 2383 (offset -3 lines).
Hunk #3 succeeded at 2398 (offset -3 lines).
patch unexpectedly ends in middle of line
Hunk #4 succeeded at 2427 (offset -3 lines).

results after reboot with new kernel:

ata7.00: 16 bytes trailing data
cdrom: This disc doesn't have any tracks I recognize!
ata7.00: 16 bytes trailing data
ata7.00: 16 bytes trailing data
ata7.00: 16 bytes trailing data
ata7.00: 16 bytes trailing data
ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
ata7.00: cmd a0/01:00:00:00:80/00:00:00:00:00/a0 tag 0 cdb 0x2a data 32768 out
         res 40/00:03:00:00:00/00:00:00:00:00/b0 Emask 0x4 (timeout)
ata7: port is slow to respond, please be patient (Status 0xd8)
ata7: device not ready (errno=-16), forcing hardreset
ata7: soft resetting port
ata7.00: configured for UDMA/66
ata7.01: configured for UDMA/33
ata7: EH complete
ata7.00: 16 bytes trailing data
Comment 12 Albert Lee 2007-09-26 02:56:26 UTC
Ok, Alan's patch doesn't help for your problem.

You are buring with the PX-760A drive, connected to the ICH-7 IDE controller, right?

I wonder where the 16-bytes trailing data come from...
Could you try burning DVD with k3b, with lower speed (say, 4x), and see if it makes any difference? Thanks.
Comment 13 Bjoern Olausson 2007-09-26 03:30:29 UTC
Jupp, PX-760A is primary master, PX-130A is primary slave both jumpered with "cable select" connected on the ICH-7 PATA Controller

If I insert a DVD, I see the following:
Sep 26 12:23:54 freax ata7.00: 16 bytes trailing data
Sep 26 12:23:54 freax cdrom: This disc doesn't have any tracks I recognize!

All testing was done with DVD-R 4x Media.
I tried to simulate writing --> Fails
Itried real writing --> Fails

Both with the same error mesage.

I'll try to burn with 2x speed.

Do you want to have ssh? ;-) To take a closer look at that beast?

By the way, I found more users with the same problem (other hardware)
But they will not report there problem here... thougt I encouraged them...

regards
Bjoern
Comment 14 Bjoern Olausson 2007-09-26 04:49:28 UTC
Created attachment 12952 [details]
dvd-proper.patch

Okay, I gave the patch a second chance and applied it manually and than diffed them (the patch is against 2.6.23-rc8)

4 tests to determin if the patch is working. Also if the test passed, there is the error message after the burning is complete.

And why faild the simulation?....

a) Simulating a data DVD-R at 4x speed -----> Success!
Sep 26 12:37:33 freax ata7.00: 16 bytes trailing data
Sep 26 12:51:51 freax ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
Sep 26 12:51:51 freax ata7.00: cmd a0/00:00:00:04:00/00:00:00:00:00/a0 tag 0 cdb 0xad data 4 in
Sep 26 12:51:51 freax res 40/00:03:00:08:00/00:00:00:00:00/b0 Emask 0x4 (timeout)
Sep 26 12:51:52 freax ata7: soft resetting port
Sep 26 12:51:53 freax ata7.00: configured for UDMA/66
Sep 26 12:51:53 freax ata7.01: configured for UDMA/33
Sep 26 12:51:53 freax ata7: EH complete
Sep 26 12:51:53 freax ata7.00: 16 bytes trailing data

b) Burning a data DVD-R at 4x speed --------> Success!
Sep 26 12:53:57 freax ata7.00: 16 bytes trailing data
Sep 26 12:53:57 freax cdrom: This disc doesn't have any tracks I recognize!
Sep 26 13:09:51 freax ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
Sep 26 13:09:51 freax ata7.00: cmd a0/00:00:00:04:00/00:00:00:00:00/a0 tag 0 cdb 0xad data 4 in
Sep 26 13:09:51 freax res 40/00:02:00:08:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
Sep 26 13:09:53 freax ata7: soft resetting port
Sep 26 13:09:53 freax ata7.00: configured for UDMA/66
Sep 26 13:09:54 freax ata7.01: configured for UDMA/33
Sep 26 13:09:54 freax ata7: EH complete
Sep 26 13:09:54 freax ata7.00: 16 bytes trailing data


c) Simulating a Video DVD-R at 4x speed ----> FAILED!
Sep 26 13:10:46 freax cdrom: This disc doesn't have any tracks I recognize!
Sep 26 13:11:07 freax ata7.00: 16 bytes trailing data
Sep 26 13:22:08 freax ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
Sep 26 13:22:08 freax ata7.00: cmd a0/01:00:00:00:80/00:00:00:00:00/a0 tag 0 cdb 0x2a data 32768 out
Sep 26 13:22:08 freax res 40/00:03:00:00:00/00:00:00:00:00/b0 Emask 0x4 (timeout)
Sep 26 13:22:13 freax ata7: port is slow to respond, please be patient (Status 0xd8)
Sep 26 13:22:18 freax ata7: device not ready (errno=-16), forcing hardreset
Sep 26 13:22:18 freax ata7: soft resetting port
Sep 26 13:22:18 freax ata7.00: configured for UDMA/66
Sep 26 13:22:18 freax ata7.01: configured for UDMA/33
Sep 26 13:22:18 freax ata7: EH complete
Sep 26 13:22:24 freax ata7.00: 16 bytes trailing data

d) Burning a Video DVD-R at 4x speed -------> SUCCESS!
Sep 26 13:24:08 freax cdrom: This disc doesn't have any tracks I recognize!
Sep 26 13:24:17 freax ata7.00: 16 bytes trailing data
Sep 26 13:39:45 freax ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
Sep 26 13:39:45 freax ata7.00: cmd a0/00:00:00:04:00/00:00:00:00:00/a0 tag 0 cdb 0xad data 4 in
Sep 26 13:39:45 freax res 40/00:02:00:08:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
Sep 26 13:39:46 freax ata7: soft resetting port
Sep 26 13:39:47 freax ata7.00: configured for UDMA/66
Sep 26 13:39:47 freax ata7.01: configured for UDMA/33
Sep 26 13:39:47 freax ata7: EH complete
Sep 26 13:39:47 freax ata7.00: 16 bytes trailing data
Comment 15 Bjoern Olausson 2007-09-27 03:21:54 UTC
VideoDVD burning faild now....

ata7.00: 16 bytes trailing data
ata7.00: 16 bytes trailing data
cdrom: This disc doesn't have any tracks I recognize!
ata7.00: 16 bytes trailing data
ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
ata7.00: cmd a0/01:00:00:00:80/00:00:00:00:00/a0 tag 0 cdb 0x2a data 32768 out
         res 40/00:03:00:00:00/00:00:00:00:00/b0 Emask 0x4 (timeout)
ata7: port is slow to respond, please be patient (Status 0xd8)
ata7: device not ready (errno=-16), forcing hardreset
ata7: soft resetting port
ata7.00: configured for UDMA/66
ata7.01: configured for UDMA/33
ata7: EH complete
ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
ata7.00: cmd a0/00:00:00:04:00/00:00:00:00:00/a0 tag 0 cdb 0xad data 4 in
         res 40/00:02:00:08:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
ata7: soft resetting port
ata7.00: configured for UDMA/66
ata7.01: configured for UDMA/33
ata7: EH complete
ata7.00: 16 bytes trailing data
Comment 16 Bjoern Olausson 2007-09-27 07:16:25 UTC
That's the result when burning a CD-R it is completely different....

ata7.00: 16 bytes trailing data
cdrom: This disc doesn't have any tracks I recognize!
scsi: unknown opcode 0xe9
scsi: unknown opcode 0xed
scsi: unknown opcode 0xf5
cdrom: This disc doesn't have any tracks I recognize!
scsi: unknown opcode 0xeb
Comment 17 Bjoern Olausson 2007-09-27 07:25:51 UTC
another try with a Video-DVD:

ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
ata7.00: cmd a0/01:00:00:00:80/00:00:00:00:00/a0 tag 0 cdb 0x2a data 32768 out
         res 40/00:03:00:00:00/00:00:00:00:00/b0 Emask 0x4 (timeout)
ata7: port is slow to respond, please be patient (Status 0xd8)
ata7: device not ready (errno=-16), forcing hardreset
ata7: soft resetting port
ata7.00: configured for UDMA/66
ata7.01: configured for UDMA/33
ata7: EH complete
ata7.00: 16 bytes trailing data
Comment 18 Bjoern Olausson 2007-10-11 04:45:10 UTC
Okay, to burn some DVDs I connected the two drives to the jmicron pata controller...

I was abel to burn DVDs.... hurrray

After the DVD is finished, there is still the "exception Emask" but the DVD works fine and I was able to burn all my DVDs

thats the dmsg output:

ata9.00: 16 bytes trailing data
ata9.00: 16 bytes trailing data
cdrom: This disc doesn't have any tracks I recognize!
Oct 11 12:58:12 freax ata9.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
Oct 11 12:58:12 freax ata9.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0xad data 4 in
Oct 11 12:58:12 freax res 40/00:02:00:08:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
Oct 11 12:58:12 freax ata9: soft resetting port
Oct 11 12:58:12 freax ata9.00: configured for UDMA/66
Oct 11 12:58:12 freax ata9.01: configured for UDMA/100
Oct 11 12:58:12 freax ata9: EH complete
Oct 11 12:58:12 freax ata9.00: 16 bytes trailing data
Comment 19 Tejun Heo 2007-10-18 07:29:00 UTC
Created attachment 13198 [details]
atapi-dma-for-rw-only.patch

Please apply this patch on top of 2.6.23 and see whether the problem goes away.  Thanks.
Comment 20 Bjoern Olausson 2007-10-19 07:04:58 UTC
Apllied it and

1. run: simulation --> Success
Oct 19 15:10:21 freax ata7.00: 16 bytes trailing data
Oct 19 15:10:21 freax ata7.00: 16 bytes trailing data
Oct 19 15:10:22 freax cdrom: This disc doesn't have any tracks I recognize!
Oct 19 15:25:42 freax ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
Oct 19 15:25:42 freax ata7.00: cmd a0/00:00:00:04:00/00:00:00:00:00/a0 tag 0 cdb 0xad data 4 in
Oct 19 15:25:42 freax res 40/00:02:00:08:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
Oct 19 15:25:42 freax ata7.00: status: { DRDY }
Oct 19 15:25:44 freax ata7: soft resetting link
Oct 19 15:25:44 freax ata7.00: configured for UDMA/66
Oct 19 15:25:44 freax ata7.01: configured for UDMA/33
Oct 19 15:25:44 freax ata7: EH complete
Oct 19 15:25:44 freax ata7.00: 16 bytes trailing data

2. run: burning --> Success
Oct 19 15:28:50 freax ata7.00: 16 bytes trailing data
Oct 19 15:28:50 freax cdrom: This disc doesn't have any tracks I recognize!
Oct 19 15:44:43 freax ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
Oct 19 15:44:43 freax ata7.00: cmd a0/00:00:00:04:00/00:00:00:00:00/a0 tag 0 cdb 0xad data 4 in
Oct 19 15:44:43 freax res 40/00:02:00:08:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
Oct 19 15:44:43 freax ata7.00: status: { DRDY }
Oct 19 15:44:45 freax ata7: soft resetting link
Oct 19 15:44:46 freax ata7.00: configured for UDMA/66
Oct 19 15:44:46 freax ata7.01: configured for UDMA/33
Oct 19 15:44:46 freax ata7: EH complete
Oct 19 15:44:46 freax ata7.00: 16 bytes trailing data

3. run: burning video dvd project --> Success

All three DVDs are working perfekt!
I am just couriouse about the "error" message that comes after the burning process was finished and the cache was flushed. Is it a normal behavior to reset the bus?

FIXED?

Thanks and regards
Bjoern
Comment 21 Tejun Heo 2007-10-19 18:13:30 UTC
Hmm... It seems some part of the problem is solved but not all.  It could just be that the device is quirky.  Some devices need media reload (eject and re-insert) to properly recognize newly burnt media.  What about other operations?  Do ripping and copying data from cd/dvd work fine without any error message?
Comment 22 Tejun Heo 2007-10-19 18:20:49 UTC
Re-reading the bug report... Okay, there never was a problem with 'reading' part of operations but writing problems are intermittent, so please test writing more thoroughly.  Timeout after successful burning seems to be caused by quirky device.  If you tell the burning program to eject after burning, does the error message disappear?
Comment 23 Bjoern Olausson 2007-10-20 08:08:10 UTC
On 10/20/07, bugme-daemon@bugzilla.kernel.org
<bugme-daemon@bugzilla.kernel.org> wrote:
> ------- Comment #22 from htejun@gmail.com  2007-10-19 18:20 -------
> Re-reading the bug report... Okay, there never was a problem with 'reading'
> part of operations but writing problems are intermittent, so please test
> writing more thoroughly.  Timeout after successful burning seems to be caused
> by quirky device.  If you tell the burning program to eject after burning,
> does
> the error message disappear?
>

I burnd about 6 DVDs  video and/or data everything works fine.
I'll test ripping and audi-cd creation.

And I'll test the "eject" option in k3b

I'll report soon.
Comment 24 Bjoern Olausson 2007-10-20 08:15:20 UTC
Ripping result (done with KAudioCreator):

Worked fine. No problems on the end user side, thought there are som messages...

Here's the dmsg output:

printk: 2368 messages suppressed.
sg_write: data in/out 30576/30576 bytes for SCSI command 0xbe--guessing data in;
   program kio_audiocd not setting count and/or reply_len properly
printk: 2344 messages suppressed.
sg_write: data in/out 7056/7056 bytes for SCSI command 0xbe--guessing data in;
   program kio_audiocd not setting count and/or reply_len properly
printk: 2308 messages suppressed.
sg_write: data in/out 30576/30576 bytes for SCSI command 0xbe--guessing data in;
   program kio_audiocd not setting count and/or reply_len properly
Comment 25 Bjoern Olausson 2007-10-20 08:53:10 UTC
Okay, that happens with the "eject" option after I burnd a data DVD:

ata7.00: 16 bytes trailing data
cdrom: This disc doesn't have any tracks I recognize!
ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
ata7.00: cmd a0/00:00:00:04:00/00:00:00:00:00/a0 tag 0 cdb 0xad data 4 in
         res 40/00:02:00:08:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
ata7.00: status: { DRDY }
ata7: soft resetting link
ata7.00: configured for UDMA/66
ata7: EH complete
ata7.00: 16 bytes trailing data



AudioCD creation worked fine and CD plays in a standalone CD/DVD-Player. (burned with eject option)

cdrom: This disc doesn't have any tracks I recognize!
end_request: I/O error, dev sr0, sector 0
printk: 1 messages suppressed.
Buffer I/O error on device sr0, logical block 0
Buffer I/O error on device sr0, logical block 1
Buffer I/O error on device sr0, logical block 2
Buffer I/O error on device sr0, logical block 3
Buffer I/O error on device sr0, logical block 4
Buffer I/O error on device sr0, logical block 5
Buffer I/O error on device sr0, logical block 6
Buffer I/O error on device sr0, logical block 7
end_request: I/O error, dev sr0, sector 0
Buffer I/O error on device sr0, logical block 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
end_request: I/O error, dev sr0, sector 0
end_request: I/O error, dev sr0, sector 4
scsi: unknown opcode 0xe9
scsi: unknown opcode 0xed
scsi: unknown opcode 0xf5
ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
ata7.00: cmd a0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x1b data 0
         res 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
ata7.00: status: { DRDY }
ata7: port is slow to respond, please be patient (Status 0xd0)
ata7: soft resetting link
ata7.00: configured for UDMA/66
ata7: EH complete
cdrom: This disc doesn't have any tracks I recognize!

Hope this helps
Comment 26 Tejun Heo 2007-10-22 02:10:20 UTC
Thanks.  We are currently trying to determine what to do about ATAIP DMA and really need to verify that the patch actually fixes burning and the result isn't random, so can you please perform controlled test?  e.g.

1. prep the same hardware/software configuration, image and media

2. boot unpatched kernel and try to burn using the image, reboot and repeat several times (3 or 5?).  Record program output and dmesg.  Also, please turn on CONFIG_PRINTK_TIME.

3. boot patched but otherwise identical kernel and do the same as #2.

Thanks a lot.
Comment 27 Bjoern Olausson 2007-10-22 16:32:52 UTC
I'll test it and report in a day or two.

Thanks for the work!
Comment 28 Bjoern Olausson 2007-10-24 15:36:30 UTC
Just a quick update:

Today I wanted to try your p5wdh-workaround-2.6.23.1.patch (http://bugzilla.kernel.org/show_bug.cgi?id=8923)

AND I gave DVD-burning a shot....

it works...

here some results:

DATA-DVD:
Oct 25 00:09:17 freax [  164.255783] ata7.00: 16 bytes trailing data
Oct 25 00:09:18 freax [  164.347011] cdrom: This disc doesn't have any tracks I recognize!
Oct 25 00:10:01 freax cron[9721]: (root) CMD (test -x /usr/sbin/run-crons && /usr/sbin/run-crons )
Oct 25 00:10:17 freax lircd-0.8.3pre1[7665]: accepted new client on /dev/lircd
Oct 25 00:10:17 freax lircd-0.8.3pre1[7665]: removed client
Oct 25 00:13:21 freax lircd-0.8.3pre1[7665]: accepted new client on /dev/lircd
Oct 25 00:13:26 freax lircd-0.8.3pre1[7665]: removed client
Oct 25 00:20:01 freax cron[10134]: (root) CMD (test -x /usr/sbin/run-crons && /usr/sbin/run-crons )
Oct 25 00:25:05 freax [ 1109.474989] ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
Oct 25 00:25:05 freax [ 1109.474998] ata7.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0xad data 4 in
Oct 25 00:25:05 freax [ 1109.475000]          res 40/00:02:00:08:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
Oct 25 00:25:07 freax [ 1111.360120] ata7: soft resetting port
Oct 25 00:25:07 freax [ 1111.822243] ata7.00: configured for UDMA/66
Oct 25 00:25:07 freax [ 1111.822359] ata7: EH complete


AUDIO-CD:
Oct 25 00:25:14 freax [ 1119.217820] ata7.00: 16 bytes trailing data
Oct 25 00:26:39 freax [ 1203.571288] cdrom: This disc doesn't have any tracks I recognize!
Oct 25 00:29:32 freax [ 1375.911192] scsi: unknown opcode 0xe9
Oct 25 00:29:32 freax [ 1375.911207] scsi: unknown opcode 0xed
Oct 25 00:29:39 freax [ 1383.399893] scsi: unknown opcode 0xf5
Oct 25 00:30:01 freax cron[10701]: (root) CMD (test -x /usr/sbin/run-crons && /usr/sbin/run-crons )
Oct 25 00:30:31 freax lircd-0.8.3pre1[7665]: accepted new client on /dev/lircd
Oct 25 00:32:28 freax [ 1552.090128] scsi: unknown opcode 0xeb

I'll do some more tests in this week... just wanted to let you know that it seems to work...

But I'll have to test with Both DVD-RW and DVD-ROM connected to the same bus as Master/Slave. Currently onle the DVD-RW is attached to the intel ICH7 BUS. The CD-R is attached to the jmicron PATA port.

I'll investigate further with 2.6.23.1

regards
Bjoern
Comment 29 Bjoern Olausson 2007-10-25 09:47:25 UTC
Okay, please kick me if something sounds stupid here:

I cant't reproduce the bug any longer. Not with stock 2.6.23 nor with stock 2.6.23.1.

After the first report that it worked (Comment #20) I attached the DVD-R to the jmicron PATA port so I can read a DVD while burning a DVD on the ICH7 PATA port.

Now you reqested to do some more test. I did. First I have done was booting a stock 2.6.23.1 Kernel with your p5wdh-workaround-2.6.23.1.patch. I kenw there were not much changes in the 2.6.23 -> 2.6.23.1. So my thoughts were the following: If dvd burning fails with 2.6.23 it should fail with 2.6.23.1 (with asus patch). But no it didn't. I simulated 2 or 3 DVDs, burnd 3. And everything was fine. So I booted a stock 2.6.23.1.... same result it works. Strange... So I went back to stock 2.6.23 where I was shure the bug should occure. But no, it didn't. Okay, maybe it's because I changed the HW setup. So I reverted everything back to the state where I knew the bug occured. Same cables, same DVD-RW and DVD-R, exactly same setup, so the bug should occure with stock 2.6.23. But no. I doesn't right now I am burning my 6th DVD....

(all kernels have the same .config)

Linux freax 2.6.23 #2 SMP PREEMPT Thu Oct 25 00:03:01 CEST 2007 x86_64 Intel(R) Core(TM)2 CPU 6600 @ 2.40GHz GenuineIntel GNU/Linux

heres dmsg from stock 2.6.23:

[  284.297456] cdrom: This disc doesn't have any tracks I recognize!
[  284.332476] ata7.00: 16 bytes trailing data
[  284.418907] ata7.00: 16 bytes trailing data
[ 1131.439997] ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
[ 1131.440007] ata7.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0xad data 4 in
[ 1131.440008]          res 40/00:02:00:08:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
[ 1132.714517] ata7: soft resetting port
[ 1133.346171] ata7.00: configured for UDMA/66
[ 1133.503662] ata7.01: configured for UDMA/33
[ 1133.503788] ata7: EH complete
[ 1139.606581] ata7.00: 16 bytes trailing data
[ 1802.179940] ata7.00: 16 bytes trailing data
[ 1802.343600] cdrom: This disc doesn't have any tracks I recognize!
[ 2754.114268] ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
[ 2754.114277] ata7.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0xad data 4 in
[ 2754.114279]          res 40/00:02:00:08:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
[ 2755.946803] ata7: soft resetting port
[ 2756.561746] ata7.00: configured for UDMA/66
[ 2756.718309] ata7.01: configured for UDMA/33
[ 2756.718323] ata7: EH complete
[ 2764.255292] ata7.00: 16 bytes trailing data
[ 2846.369243] ata7.00: 16 bytes trailing data
[ 2846.482295] cdrom: This disc doesn't have any tracks I recognize!
[ 3837.044918] ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
[ 3837.044928] ata7.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0xad data 4 in
[ 3837.044929]          res 40/00:02:00:08:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
[ 3838.928963] ata7: soft resetting port
[ 3839.557637] ata7.00: configured for UDMA/66
[ 3839.714177] ata7.01: configured for UDMA/33
[ 3839.714195] ata7: EH complete
[ 3853.686851] ata7.00: 16 bytes trailing data
[ 4277.790835] ata7.00: 16 bytes trailing data
[ 4277.894865] cdrom: This disc doesn't have any tracks I recognize!
[ 5270.918308] ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
[ 5270.918317] ata7.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0xad data 4 in
[ 5270.918318]          res 40/00:02:00:08:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
[ 5272.955809] ata7: soft resetting port
[ 5273.570934] ata7.00: configured for UDMA/66
[ 5273.727466] ata7.01: configured for UDMA/33
[ 5273.727487] ata7: EH complete

Could anybody throw some light on this?
I am completely confused.

Okay, now I'll reboot with 2.6.23.1 with atapi-dma-for-rw-only.patch

*confused*

regards
Bjoern
Comment 30 Bjoern Olausson 2007-10-25 09:57:41 UTC
Patching 2.6.23.1:

root@freax $ patch -p1 < atapi-dma-for-rw-only.patch
patching file drivers/ata/libata-core.c
Hunk #2 succeeded at 4194 (offset -253 lines).

rebooting
Comment 31 Bjoern Olausson 2007-10-25 11:00:55 UTC
results with 2.6.23.1 with your atapi-dma-for-rw-only.patch

works fine... but stil the bus resest after the DVD is finish.

[  231.847175] ata7.00: 16 bytes trailing data
[  403.273211] ata7.00: 16 bytes trailing data
[  403.376839] cdrom: This disc doesn't have any tracks I recognize!
[  817.730311] operapluginwrap[11740]: segfault at 0000000000000008 rip 0000000000410c80 rsp 00007fff39887020 error 4
[ 1282.510477] ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
[ 1282.510487] ata7.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0xad data 4 in
[ 1282.510488]          res 40/00:02:00:08:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
[ 1284.494911] ata7: soft resetting port
[ 1285.109426] ata7.00: configured for UDMA/66
[ 1285.267114] ata7.01: configured for UDMA/33
[ 1285.267203] ata7: EH complete
[ 1294.296803] ata7.00: 16 bytes trailing data
Comment 32 Tejun Heo 2007-10-26 00:34:40 UTC
So, it's the same with or without the patch, right?
Comment 33 Bjoern Olausson 2007-10-26 08:56:55 UTC
right... but wired is that I can't reproduce the bug.
Bevor i couldn't burn a DVD it faild ad some percent. It looked like the bus was reseted during the burn proces. But I cant't reproduce this behavior now.

But non the less, for now, the result with atapi-dma-for-rw-only patch and without patch is the same.

But why the heck can't I reproduce the initial bug which made me file this.
The bug really should occure with unpached stock 2.6.23 kernel but it doesn't.
I am going nuts.

Okay, lets thread the "bus reset during burning" as resolved and concentrate on the busreset after successful writing a DVD...

Anyway, I'll burn some more DVDs with 2.6.23.1 and your p5wdh-workaround-2.6.23.1.patch
Comment 34 Bjoern Olausson 2007-10-26 09:07:27 UTC
Okay, I just want to summarize:

--> I wasn't able to burn DVDs with the writer connected to ICH7 up to 2.6.23

--> Connected the writer to the jmicron controller and was able to burn DVDs

--> Connected writer back to ICH7, applied your patch atapi-dma-for-rw-only.patch and was able to burn DVDs

--> Tried a stock 2.6.23.1 with p5wd workaround patch and gave DVD writing a chance... it worked. *wondering* cause it should have faild 

--> Tried a stock 2.6.23.1 ... it worked. *wondering* cause it should have faild

--> Tried a stock 2.6.23 ... it worked. *wondering* cause it should have faild

--> Tried 2.6.23.1 with atapi-dma-for-rw-only.patch... no difference. it works.

The bus reset, after writing is complete, is found in all test cases (okay, where the DVD writing fails not, but i guess you knew that ;-)

Actually I hope your not that confused like I am.
Comment 35 Tejun Heo 2007-10-26 13:53:03 UTC
Any chance you were booting the wrong kernel (the patched one)?  That happens to me all the time.  A good way to tell is to add a simple printk or set CONFIG_LOCALVERSION.  Also, on jmicron controller after successful burning, timeout and the following reset occurs too right?  Thanks.
Comment 36 Bjoern Olausson 2007-10-26 19:41:30 UTC
I am shure, for lets say 99%, I booted the right kernel...
But I'll double check this.

And yes, as I postet in comment 18, the bus reset occures also on the jmicron.

But I'll doublecheck the kernel version and patch level!

Could there be anoter factor we miss? glibc? or any other hardware close software?

regards
and thanks a lot for your pations and work! I really appreciate it.

Bjoern
Comment 37 Bjoern Olausson 2007-10-26 19:41:56 UTC
I am shure, for lets say 99%, I booted the right kernel...
But I'll double check this.

And yes, as I postet in comment 18, the bus reset occures also on the jmicron.

But I'll doublecheck the kernel version and patch level!

Could there be anoter factor we miss? glibc? or any other hardware close software?

regards
and thanks a lot for your pations and work! I really appreciate it.

Bjoern
Comment 38 Bjoern Olausson 2007-10-26 19:44:11 UTC
Sory, I hit the radiobutton "Defer bug, changing resolution to WILL_FIX_LATER" instad of commit... but was to fast with my second klick on Commit ;-)

Sry.
Bjoern
Comment 39 Bjoern Olausson 2007-10-27 13:04:28 UTC
blub@freax $ uname -a
Linux freax 2.6.23.1p5wdh-workaround #1 SMP PREEMPT Sat Oct 27 21:08:03 CEST 2007 x86_64 Intel(R) Core(TM)2 CPU 6600 @ 2.40GHz GenuineIntel GNU/Linux

Burned 3. DVDs with the above Kernel (only applied p5wdh-workaround patch)

All DVDs are working fine (actually they should have failed...). And of yourse the mandatory busreset after the writing process.:

[ 1293.230072] ata7.01: configured for UDMA/33
[ 1293.230089] ata7: EH complete
[ 1300.759543] ata7.00: 16 bytes trailing data
[ 1382.707458] ata7.00: 16 bytes trailing data
[ 1382.815043] cdrom: This disc doesn't have any tracks I recognize!
[ 2343.885066] ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
[ 2343.885074] ata7.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0xad data 4 in
[ 2343.885076]          res 40/00:02:00:08:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
[ 2345.872123] ata7: soft resetting port
[ 2346.488138] ata7.00: configured for UDMA/66
[ 2346.646619] ata7.01: configured for UDMA/33
[ 2346.646730] ata7: EH complete
[ 2354.004240] ata7.00: 16 bytes trailing data

Now rebooting to atapi-dma-for-rw-only patched kernel (with p5wdh-workaround, I guess they don't interfere?)
Comment 40 Bjoern Olausson 2007-10-28 07:44:33 UTC
blub@freax $ uname -a
Linux freax 2.6.23.1p5wdh-workaround_atapi-dma-for-rw-only #2 SMP PREEMPT Sat Oct 27 21:10:46 CEST 2007 x86_64 Intel(R) Core(TM)2 CPU 6600 @ 2.40GHz GenuineIntel GNU/Linux

Now I tested your atapi-dma-for-rw-only patch... right bevore the disk is ejected, the bus is reset as usual. But I burned 3 disks successful. Your patch does not make any difference now. (dmesg below)

So now I am for 100% shure I booted the right kernel. The HW setup is exactly the same as when I first posted the issue but I cant't reproduce it now...


[  411.900219] ata7.00: 16 bytes trailing data
[  411.995776] cdrom: This disc doesn't have any tracks I recognize!
[ 1356.072398] operapluginwrap[15868]: segfault at 0000000000000000 rip 000000000040e8c3 rsp 00007fff018f1fc0 error 4
[ 1461.431011] ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
[ 1461.431124] ata7.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0xad data 4 in
[ 1461.431125]          res 40/00:02:00:08:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
[ 1463.264162] ata7: soft resetting port
[ 1463.879462] ata7.00: configured for UDMA/66
[ 1464.037209] ata7.01: configured for UDMA/33
[ 1464.037483] ata7: EH complete


Regards
Bjoern
Comment 41 Bjoern Olausson 2007-10-28 07:55:11 UTC
By the way, here's the debugging output from k3b:

http://rafb.net/p/aKX2fX38.html

thanks for your help
Bjoern
Comment 42 Tejun Heo 2007-10-29 03:39:33 UTC
Created attachment 13309 [details]
debug.patch

Please apply the attached patch and report the result.  Thanks.
Comment 43 Bjoern Olausson 2007-10-29 04:43:00 UTC
blub@freax $ uname -a
Linux freax 2.6.23.1-p5wdh-workaround_-_debug #1 SMP PREEMPT Mon Oct 29 12:17:00 CET 2007 x86_64 Intel(R) Core(TM)2 CPU 6600 @ 2.40GHz GenuineIntel GNU/Linux

Everything as usual.. writing works, bus reset bevor CD has been ejected.

Here's the result:

[  137.424987] ata7.00: 16 bytes trailing data
[  137.424994] ata7.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0xac data 8 in
[  137.424996]          <4>ata7.00: 16 bytes trailing data
[  203.897640] ata7.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0xac data 8 in
[  203.897642]          <6>cdrom: This disc doesn't have any tracks I recognize!
[ 1159.287100] ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
[ 1159.287109] ata7.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0xad data 4 in
[ 1159.287111]          res 40/00:02:00:08:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
[ 1161.170500] ata7: soft resetting port
[ 1161.631531] ata7.00: configured for UDMA/66
[ 1161.631555] ata7: EH complete
[ 1167.753098] ata7.00: 16 bytes trailing data
[ 1167.753105] ata7.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0xac data 8 in
[ 1167.753107]

Complete dmsg log:
http://rafb.net/p/TER54o54.html

regards
Bjoern
Comment 44 Tejun Heo 2007-10-29 05:03:30 UTC
The patch was to find out which command was triggering the 16 bytes trailing data workaround.  Can you ship the drive to me?  I can pay via paypal unless it's too expensive.
Comment 45 Bjoern Olausson 2007-10-29 05:34:33 UTC
Why not...
Send me your contact information to lkmlist[at]gmail[dot]com or the address found on http://olausson.de/contact/ 

I'll check the shipping prices.

regards
Bjoern
Comment 46 Tejun Heo 2007-11-12 00:17:56 UTC
NOTE: The package hasn't arrived yet but I think I've identified what's wrong with libata ATAPI handling.  I'm working on a general solution now.  Will test on 760A too when it arrives.
Comment 47 Natalie Protasevich 2008-02-07 00:35:29 UTC
Any updates on this problem, has it been fixed?
Thanks.
Comment 48 Bjoern Olausson 2008-02-11 13:59:42 UTC
The device has finally reached Tejun after 2 month (Germany --> Korea). I can't reproduce this error any longer. So we will have to wait untill Tejun gives any updates.

regards
Bjoern
Comment 49 Tejun Heo 2008-02-11 17:02:02 UTC
Yeah, it's on my desk now.  I'm buried under bug reports so please gimme some time.  I'll get to it next week.  Thanks.
Comment 50 Tejun Heo 2008-04-02 19:19:07 UTC
Okay, just tested it on pata_jmicron and ich7 ata_piix (different board but should be pretty similar to your board).  Everything works just fine.  I've tested recording with both wodim directly and via k3b and kernel version libata-dev#upstream, 2.6.24.4 and 2.6.23.1.

The only thing I can think of is k3b issuing commands where data length doesn't match buffer length and libata choking on it.  Prior to 2.6.25-rcX, libata didn't handle such cases too well and could trigger exceptions.  The version of k3b I tested doesn't issue any such command, so I couldn't really verify the theory.

Bjoern, which distro were you using when trying to burn?

Jeff, I think this one can be closed now.
Comment 51 Bjoern Olausson 2008-04-04 14:48:16 UTC
I am still using Gentoo Linux, with vanilla-sources.

The new SATA writer works without any errors.

Ah, maybe I have the chance to test the device once more. A friend of mine has the PX-760A and he's comming to visit me this weekend... lets see if I can reproduce this error with all new kernel and software ;-)

If he is not willing to bring his writer ;-) I have no chance to reproduce this bug or to confirm it is cured.

I'll report the next week.

kind regards
Bjoern
Comment 52 Tejun Heo 2008-04-04 16:57:46 UTC
I can send it back too.  :-)  Let me know how it goes.
Comment 53 Bjoern Olausson 2008-04-10 10:29:54 UTC
Okay, here we go, I got my hands on another PX-760A... so no need to wait another 3 month to reproduce the bug and send the drive again to Tejun... (maybe this gets fix in kernel 3.0 that way ;-) )

I forgot to dump the dmesg when the drive was attached to the ICH7 so in the log (dmesg-ICH7.log) file the information below is missing cause I rebooted with the drive attached to the ICH7 after I tested it on the JMICRON just to get a dmesg for the ICH7 Port. The log (dmesg-jmicron.log) for the jmicron test session is complete.

In all cases I was able to write a full functional disc!

Notice the blacklist entry in the jmicron dmesg log!

For now I don't have the writer any more and can't do any more test.

##############################################################
#########ATTACHED TO ICH7 dmesg-ICH7.log######################
##############################################################

#########INSERTING EMPTY DVD###############
###########################################
Apr 10 17:54:39 freax [  821.929219] cdrom: This disc doesn't have any tracks I recognize!
Apr 10 17:55:09 freax [  886.671541] cdrom: This disc doesn't have any tracks I recognize!

#########Writing finished, DVD ejected by K3B################
#############################################################
Apr 10 18:05:46 freax [ 2260.159472] ata7.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
Apr 10 18:05:46 freax [ 2260.159484] ata7.00: cmd a0/00:00:00:04:00/00:00:00:00:00/a0 tag 0 pio 16388 in
Apr 10 18:05:46 freax [ 2260.159485]          cdb ad 00 00 00 00 00 00 00  00 04 00 00 00 00 00 00
Apr 10 18:05:46 freax [ 2260.159487]          res 40/00:02:00:08:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
Apr 10 18:05:46 freax [ 2260.159491] ata7.00: status: { DRDY }
Apr 10 18:05:49 freax [ 2265.207651] ata7: port is slow to respond, please be patient (Status 0xd0)
Apr 10 18:05:51 freax [ 2270.204891] ata7: device not ready (errno=-16), forcing hardreset
Apr 10 18:05:51 freax [ 2270.204897] ata7: soft resetting link
Apr 10 18:05:51 freax [ 2270.665090] ata7.00: configured for UDMA/66
Apr 10 18:05:51 freax [ 2270.665995] ata7: EH complete

#########INSERTING CD-RW and quick erase RW with K3B###############
###################################################################
Apr 10 18:06:52 freax [ 2402.529807] scsi: unknown opcode 0xe9
Apr 10 18:06:52 freax [ 2402.529981] scsi: unknown opcode 0xd4
Apr 10 18:06:52 freax [ 2402.530065] scsi: unknown opcode 0xed

#########Re inserting the empty CD-RW and starting to write###############
##########################################################################
Apr 10 18:08:18 freax [ 2586.752960] cdrom: This disc doesn't have any tracks I recognize!
Apr 10 18:08:31 freax [ 2616.227527] scsi: unknown opcode 0x01
Apr 10 18:08:35 freax [ 2622.789352] scsi: unknown opcode 0xf5
Apr 10 18:09:02 freax [ 2680.938803] cdrom: This disc doesn't have any tracks I recognize!

#########Writing finished cd was ejected######################
##############################################################
Apr 10 18:17:09 freax [ 3731.266027] scsi: unknown opcode 0xeb



##############################################################
#########ATTACHED TO JMICRON dmesg-jmicron.log################
##############################################################

#########INSERTING EMPTY DVD###############
###########################################
[  196.567063] cdrom: This disc doesn't have any tracks I recognize!
[  270.702137] warning: `growisofs' uses 32-bit capabilities (legacy support in use)

#########Writing finished, DVD ejected by K3B################
#############################################################
[  730.960704] ata9.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
[  730.960715] ata9.00: cmd a0/00:00:00:04:00/00:00:00:00:00/a0 tag 0 pio 16388 in
[  730.960717]          cdb ad 00 00 00 00 00 00 00  00 04 00 00 00 00 00 00
[  730.960718]          res 40/00:02:00:08:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
[  730.960722] ata9.00: status: { DRDY }
[  733.510301] ata9: soft resetting link
[  733.972750] ata9.00: configured for UDMA/66
[  733.972768] ata9: EH complete

#########INSERTING EMPTY CD cause the RW wasn't recogniced################
##########################################################################
[  942.261308] cdrom: This disc doesn't have any tracks I recognize!

#########REMOVED EMPTY CD and tried again with RW#########################
##########################################################################
#########INSERTING CD-RW and quick erase RW with K3B###############
###################################################################
[  972.726319] scsi: unknown opcode 0xe9
[  972.726516] scsi: unknown opcode 0xd4
[  972.726600] scsi: unknown opcode 0xed

#########Re inserting the empty CD-RW and starting to write###############
##########################################################################
[ 1133.119418] cdrom: This disc doesn't have any tracks I recognize!

#########Writing finished cd was ejected######################
##############################################################
[ 1142.288507] scsi: unknown opcode 0x01
[ 1145.275459] scsi: unknown opcode 0xf5
[ 1172.017489] cdrom: This disc doesn't have any tracks I recognize!
[ 1640.595516] scsi: unknown opcode 0xeb
Comment 54 Bjoern Olausson 2008-04-10 10:30:40 UTC
Created attachment 15722 [details]
dmesg-ICH7.log
Comment 55 Bjoern Olausson 2008-04-10 10:30:58 UTC
Created attachment 15723 [details]
dmesg-jmicron.log
Comment 56 Bjoern Olausson 2008-04-10 10:33:41 UTC
I should mention the kernel version I used for testing:

stock vanilla 2.6.25-rc8


kind regards
Bjoern
Comment 57 Tejun Heo 2008-04-10 21:50:34 UTC
Thanks for testing.  Great that it works.  The exception and blacklist messages are from the SIMG4726 hanging off your second ahci port.  You're on the dreaded ASUS P5DW-DH Deluxe, right?

I'll try to see whether I can reproduce READ_DVD_STRUCTURE timeout after burning but that's probably something k3b does wrong.  Many drives don't behave well when they're asked to read from the disc they just wrote.
Comment 58 Bjoern Olausson 2008-04-11 09:03:46 UTC
Jap I am on that P5DW-DH Deluxe.

Maybe I should take a closer look on that SIMG4726 errors... (no not another bug please ;-) )
Comment 59 Tejun Heo 2008-04-11 18:21:20 UTC
Well, as long as you put the controller in ahci mode and refrain from hotplugging on that port, you should be fine.

Note You need to log in before you can comment on or make changes to this bug.