dvd+rw-tools disable DMA when burning a DVD-R

[Luc Saillard <luc@saillard.org>]

Hi,

My system is a Debian GNU/Linux (sid version), i use a 2.6.0-test11 kernel
with an Promise IDE Card where a PIONEER DVD-RW DVR-106D and a IBM hardrive
is attached. Each ide device is on a master device, i've also a Adaptec
U2940UW and a SCSI harddrive.

growisofs => 5.14.4.7.4
cdrtools  => 2.0+a19-6 (debian version)
linux     => 2.6.0-test11


I create my iso with this command line:
 mkisofs -V "BACKUP 20031201" -J -v -r -file-mode 444 -dir-mode 555 -o /mnt/space1/iso/backup.iso .
and burn with growisofs
 growisofs -Z/dev/dvd=backup.iso


When i first burn on a dvd+rw, nothing strange appear in the log. I've a
small computer (Intel Celeron 333) this is why i've bougth a promise fastrack
ide card with 2 ide ports and burn on a rw before writting a -r or +r

When i burn on a dvd-r (verbatim media 2x), i've this on the kernel.log:

Dec 16 22:37:48 darkland kernel: hdg: cdrom_decode_status: status=0x51 { DriveReady SeekComplete Error }
Dec 16 22:37:48 darkland kernel: hdg: cdrom_decode_status: error=0x80LastFailedSense 0x08 
Dec 16 22:37:48 darkland kernel: hdg: cdrom_decode_status: status=0x51 { DriveReady SeekComplete Error }
Dec 16 22:37:48 darkland kernel: hdg: cdrom_decode_status: error=0x80LastFailedSense 0x08
Dec 16 22:37:48 darkland kernel: hdg: cdrom_decode_status: status=0x51 { DriveReady SeekComplete Error }
Dec 16 22:37:48 darkland kernel: hdg: cdrom_decode_status: error=0x80LastFailedSense 0x08 
Dec 16 22:37:48 darkland kernel: hdg: cdrom_decode_status: status=0x51 { DriveReady SeekComplete Error }
Dec 16 22:37:48 darkland kernel: hdg: cdrom_decode_status: error=0x80LastFailedSense 0x08
Dec 16 22:37:48 darkland kernel: hdg: DMA disabled
Dec 16 22:37:48 darkland kernel: hdg: ide_intr: huh? expected NULL handler on exit
Dec 16 22:37:48 darkland kernel: hdg: ATAPI reset complete
Dec 16 22:37:48 darkland kernel: hdg: cdrom_decode_status: status=0x51 { DriveReady SeekComplete Error }
Dec 16 22:37:48 darkland kernel: hdg: cdrom_decode_status: error=0x80LastFailedSense 0x08
Dec 16 22:37:48 darkland kernel: hdg: cdrom_decode_status: status=0x51 { DriveReady SeekComplete Error }
Dec 16 22:37:48 darkland kernel: hdg: cdrom_decode_status: error=0x80LastFailedSense 0x08
Dec 16 22:37:48 darkland kernel: hdg: cdrom_decode_status: status=0x51 { DriveReady SeekComplete Error }
Dec 16 22:37:48 darkland kernel: hdg: cdrom_decode_status: error=0x80LastFailedSense 0x08 
Dec 16 22:37:48 darkland kernel: hdg: cdrom_decode_status: status=0x51 { DriveReady SeekComplete Error }
Dec 16 22:37:48 darkland kernel: hdg: cdrom_decode_status: error=0x80LastFailedSense 0x08
Dec 16 22:37:48 darkland kernel: hdg: ide_intr: huh? expected NULL handler on exit
Dec 16 22:37:48 darkland kernel: hdg: ATAPI reset complete
Dec 16 22:37:48 darkland kernel: hdg: cdrom_decode_status: status=0x51 { DriveReady SeekComplete Error }
Dec 16 22:37:48 darkland kernel: hdg: cdrom_decode_status: error=0x80LastFailedSense 0x08
Dec 16 22:37:48 darkland kernel: end_request: I/O error, dev hdg, sector 64
Dec 16 22:37:48 darkland kernel: Buffer I/O error on device hdg, logical block 8
Dec 16 22:37:57 darkland kernel: cdrom_newpc_intr: 4 residual after xfer
Dec 16 22:37:57 darkland kernel: hdg: cdrom_decode_status: status=0x51 { DriveReady SeekComplete Error }
Dec 16 22:37:57 darkland kernel: hdg: cdrom_decode_status: error=0x80LastFailedSense 0x08
Dec 16 22:37:57 darkland kernel: hdg: cdrom_decode_status: status=0x51 { DriveReady SeekComplete Error }
Dec 16 22:37:57 darkland kernel: hdg: cdrom_decode_status: error=0x80LastFailedSense 0x08
Dec 16 22:37:57 darkland kernel: hdg: cdrom_decode_status: status=0x51 { DriveReady SeekComplete Error }
Dec 16 22:37:57 darkland kernel: hdg: cdrom_decode_status: error=0x80LastFailedSense 0x08
Dec 16 22:37:57 darkland kernel: hdg: cdrom_decode_status: status=0x51 { DriveReady SeekComplete Error }
Dec 16 22:37:57 darkland kernel: hdg: cdrom_decode_status: error=0x80LastFailedSense 0x08
Dec 16 22:37:57 darkland kernel: hdg: ide_intr: huh? expected NULL handler on exit
Dec 16 22:37:57 darkland kernel: hdg: ATAPI reset complete
Dec 16 22:37:57 darkland kernel: hdg: cdrom_decode_status: status=0x51 { DriveReady SeekComplete Error }
Dec 16 22:37:57 darkland kernel: hdg: cdrom_decode_status: error=0x80LastFailedSense 0x08
Dec 16 22:37:57 darkland kernel: hdg: cdrom_decode_status: status=0x51 { DriveReady SeekComplete Error }
Dec 16 22:37:57 darkland kernel: hdg: cdrom_decode_status: error=0x80LastFailedSense 0x08
Dec 16 22:37:57 darkland kernel: hdg: cdrom_decode_status: status=0x51 { DriveReady SeekComplete Error }
Dec 16 22:37:57 darkland kernel: hdg: cdrom_decode_status: error=0x80LastFailedSense 0x08
Dec 16 22:37:57 darkland kernel: hdg: cdrom_decode_status: status=0x51 { DriveReady SeekComplete Error }
Dec 16 22:37:57 darkland kernel: hdg: cdrom_decode_status: error=0x80LastFailedSense 0x08
Dec 16 22:37:57 darkland kernel: hdg: ide_intr: huh? expected NULL handler on exit
Dec 16 22:37:57 darkland kernel: hdg: ATAPI reset complete
Dec 16 22:37:57 darkland kernel: hdg: cdrom_decode_status: status=0x51 { DriveReady SeekComplete Error }
Dec 16 22:37:57 darkland kernel: hdg: cdrom_decode_status: error=0x80LastFailedSense 0x08
Dec 16 22:37:57 darkland kernel: end_request: I/O error, dev hdg, sector 64
Dec 16 22:37:57 darkland kernel: Buffer I/O error on device hdg, logical block 8

The big problem is DMA is disable, and write failed ten minutes after because i
can't feed enought data for the dvd burner. I've found a workaround, just after
launching growisofs, i reenable DMA using this line:

        echo using_dma:1 > /proc/ide/hdg/settings

/dev/hdg is the pionner dvD

I want to know if i need to report this bug on the lkml if it's a kernel bug,
or it's a dvdtools bugs. I think the bug occur, when reading the toc on an empty
media.

Here my kernel log a start:

Linux version 2.6.0-test11 (luc@darkland) (version gcc 3.3.2 (Debian)) #1 Tue Dec 2 22:01:14 CET 2003
BIOS-provided physical RAM map:
 BIOS-e820: 0000000000000000 - 00000000000a0000 (usable)
 BIOS-e820: 00000000000f0000 - 0000000000100000 (reserved)
 BIOS-e820: 0000000000100000 - 0000000014000000 (usable)
 BIOS-e820: 00000000ffff0000 - 0000000100000000 (reserved)
320MB LOWMEM available.
On node 0 totalpages: 81920
  DMA zone: 4096 pages, LIFO batch:1
  Normal zone: 77824 pages, LIFO batch:16
  HighMem zone: 0 pages, LIFO batch:1
DMI 2.3 present.
Building zonelist for node : 0
Kernel command line: root=/dev/sda2 ro 
Initializing CPU#0
PID hash table entries: 2048 (order 11: 16384 bytes)
Detected 416.647 MHz processor.
Console: colour VGA+ 80x25
Memory: 321064k/327680k available (1735k kernel code, 5860k reserved, 580k data, 124k init, 0k highmem)
Calibrating delay loop... 823.29 BogoMIPS
Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
Mount-cache hash table entries: 512 (order: 0, 4096 bytes)
CPU:     After generic identify, caps: 0183f9ff 00000000 00000000 00000000
CPU:     After vendor identify, caps: 0183f9ff 00000000 00000000 00000000
CPU: L1 I cache: 16K, L1 D cache: 16K
CPU: L2 cache: 128K
CPU:     After all inits, caps: 0183f9ff 00000000 00000000 00000040
Intel machine check architecture supported.
Intel machine check reporting enabled on CPU#0.
CPU: Intel Celeron (Mendocino) stepping 00
Enabling fast FPU save and restore... done.
Checking 'hlt' instruction... OK.
POSIX conformance testing by UNIFIX
NET: Registered protocol family 16
PCI: PCI BIOS revision 2.10 entry at 0xfb3b0, last bus=1
PCI: Using configuration type 1
mtrr: v2.0 (20020519)
SCSI subsystem initialized
drivers/usb/core/usb.c: registered new driver usbfs
drivers/usb/core/usb.c: registered new driver hub
PCI: Probing PCI hardware
PCI: Probing PCI hardware (bus 00)
PCI: Using IRQ router PIIX/ICH [8086/7110] at 0000:00:07.0
apm: BIOS version 1.2 Flags 0x07 (Driver version 1.16ac)
Limiting direct PCI/PCI transfers.
pty: 256 Unix98 ptys configured
Real Time Clock Driver v1.12
Linux agpgart interface v0.100 (c) Dave Jones
agpgart: Detected an Intel 440BX Chipset.
agpgart: Maximum main memory to use for agp memory: 263M
agpgart: AGP aperture is 128M @ 0xd0000000
[drm] Initialized tdfx 1.0.0 20010216 on minor 0
Serial: 8250/16550 driver $Revision: 1.90 $ 8 ports, IRQ sharing disabled
RAMDISK driver initialized: 16 RAM disks of 4096K size 1024 blocksize
loop: loaded (max 8 devices)
PCI: Found IRQ 11 for device 0000:00:09.0
PCI: Sharing IRQ 11 with 0000:00:07.2
PCI: Sharing IRQ 11 with 0000:00:11.0
3c59x: Donald Becker and others. www.scyld.com/network/vortex.html
0000:00:09.0: 3Com PCI 3c905C Tornado at 0xa400. Vers LK1.1.19
Uniform Multi-Platform E-IDE driver Revision: 7.00alpha2
ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx
PIIX4: IDE controller at PCI slot 0000:00:07.1
PIIX4: chipset revision 1
PIIX4: not 100% native mode: will probe irqs later
    ide0: BM-DMA at 0xf000-0xf007, BIOS settings: hda:pio, hdb:pio
    ide1: BM-DMA at 0xf008-0xf00f, BIOS settings: hdc:pio, hdd:pio
hda: IC35L060AVER07-0, ATA DISK drive
Using anticipatory io scheduler
ide0 at 0x1f0-0x1f7,0x3f6 on irq 14
hdc: YAMAHA CRW-F1E, ATAPI CD/DVD-ROM drive
ide1 at 0x170-0x177,0x376 on irq 15
PDC20268: IDE controller at PCI slot 0000:00:0d.0
PCI: Found IRQ 7 for device 0000:00:0d.0
PDC20268: chipset revision 2
PDC20268: 100% native mode on irq 7
    ide2: BM-DMA at 0xbc00-0xbc07, BIOS settings: hde:pio, hdf:pio
    ide3: BM-DMA at 0xbc08-0xbc0f, BIOS settings: hdg:pio, hdh:pio
hde: IC35L120AVV207-1, ATA DISK drive
ide2 at 0xac00-0xac07,0xb002 on irq 7
hdg: PIONEER DVD-RW DVR-106D, ATAPI CD/DVD-ROM drive
ide3 at 0xb400-0xb407,0xb802 on irq 7
hda: max request size: 128KiB
hda: 120103200 sectors (61492 MB) w/1916KiB Cache, CHS=65535/16/63, UDMA(33)
 hda: hda1
hde: max request size: 1024KiB
hde: 241254720 sectors (123522 MB) w/7965KiB Cache, CHS=16383/255/63, UDMA(100)
 hde: hde1 hde2 hde3
end_request: I/O error, dev hdc, sector 0
hdc: ATAPI 44X CD-ROM CD-R/RW drive, 8192kB Cache, UDMA(33)
Uniform CD-ROM driver Revision: 3.12
hdg: ATAPI 47X DVD-ROM DVD-R CD-R/RW drive, 2000kB Cache
PCI: Found IRQ 9 for device 0000:00:0b.0
scsi0 : Adaptec AIC7XXX EISA/VLB/PCI SCSI HBA DRIVER, Rev 6.2.35
        <Adaptec 2940 Ultra SCSI adapter>
        aic7880: Ultra Wide Channel A, SCSI Id=7, 16/253 SCBs

(scsi0:A:1): 20.000MB/s transfers (20.000MHz, offset 15)
  Vendor: QUANTUM   Model: XP34550S          Rev: LXQ1
  Type:   Direct-Access                      ANSI SCSI revision: 02
scsi0:A:1:0: Tagged Queuing enabled.  Depth 64
SCSI device sda: 8890760 512-byte hdwr sectors (4552 MB)
SCSI device sda: drive cache: write back
 sda: sda1 sda2
Attached scsi disk sda at scsi0, channel 0, id 1, lun 0
Attached scsi generic sg0 at scsi0, channel 0, id 1, lun 0,  type 0
drivers/usb/host/uhci-hcd.c: USB Universal Host Controller Interface driver v2.1
PCI: Found IRQ 11 for device 0000:00:07.2
PCI: Sharing IRQ 11 with 0000:00:09.0
PCI: Sharing IRQ 11 with 0000:00:11.0
uhci_hcd 0000:00:07.2: UHCI Host Controller
uhci_hcd 0000:00:07.2: irq 11, io base 0000a000
uhci_hcd 0000:00:07.2: new USB bus registered, assigned bus number 1
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 2 ports detected
Initializing USB Mass Storage driver...
drivers/usb/core/usb.c: registered new driver usb-storage
USB Mass Storage support registered.
drivers/usb/core/usb.c: registered new driver hid
drivers/usb/input/hid-core.c: v2.0:USB HID core driver
drivers/usb/core/usb.c: registered new driver usbnet
mice: PS/2 mouse device common for all mice
serio: i8042 AUX port at 0x60,0x64 irq 12
input: AT Translated Set 2 keyboard on isa0060/serio0
serio: i8042 KBD port at 0x60,0x64 irq 1
NET: Registered protocol family 2
IP: routing cache hash table of 4096 buckets, 32Kbytes
TCP: Hash tables configured (established 32768 bind 65536)
NET: Registered protocol family 1
NET: Registered protocol family 17
kjournald starting.  Commit interval 5 seconds
EXT3-fs: mounted filesystem with ordered data mode.
VFS: Mounted root (ext3 filesystem) readonly.
Freeing unused kernel memory: 124k freed
hub 1-0:1.0: new USB device on port 2, assigned address 2
input: USB HID v1.10 Mouse [Logitech USB Receiver] on usb-0000:00:07.2-2
Adding 530104k swap on /dev/sda1.  Priority:-1 extents:1
EXT3 FS on sda2, internal journal
PCI: Found IRQ 11 for device 0000:00:11.0
PCI: Sharing IRQ 11 with 0000:00:07.2
PCI: Sharing IRQ 11 with 0000:00:09.0
kjournald starting.  Commit interval 5 seconds
EXT3-fs: mounted filesystem with ordered data mode.
kjournald starting.  Commit interval 5 seconds
EXT3 FS on hde2, internal journal
EXT3-fs: mounted filesystem with ordered data mode.
kjournald starting.  Commit interval 5 seconds
EXT3 FS on hde3, internal journal
EXT3-fs: mounted filesystem with ordered data mode.


Thanks for your great product, i can use and burn on dvd.

Luc