cdrecord/k3b/nautilus problem

[Richard Kleeman]

On Hoary I have had problems burning cds. Many strange kernel scsi messages appear
and the burning is very unreliable (sometimes works sometimes not). Here is some
relevant information:

k3b cd-rw erase appears to work although the following messages appear in the
dmesg log

scsi2:0:4:0: Attempting to abort cmd f0351380: 0x0 0x0 0x0 0x0 0x0 0x0
scsi2: At time of recovery, card was not paused
>>>>>>>>>>>>>>>>>> Dump Card State Begins <<<<<<<<<<<<<<<<<
scsi2: Dumping Card State at program address 0xe0 Mode 0x11
Card was paused
HS_MAILBOX[0x0] INTCTL[0x80]:(SWTMINTMASK) SEQINTSTAT[0x0]
SAVED_MODE[0x11] DFFSTAT[0x19]:(CURRFIFO_1|FIFO0FREE)
SCSISIGI[0x86]:(P_COMMAND|REQI|BSYI) SCSIPHASE[0x10]:(COMMAND_PHASE)
SCSIBUS[0x0] LASTPHASE[0x80]:(P_COMMAND) SCSISEQ0[0x0]
SCSISEQ1[0x12]:(ENAUTOATNP|ENRSELI) SEQCTL0[0x0] SEQINTCTL[0x0]
SEQ_FLAGS[0x40]:(NO_CDB_SENT) SEQ_FLAGS2[0x0] SSTAT0[0x2]:(SPIORDY)
SSTAT1[0x19]:(REQINIT|BUSFREE|PHASEMIS) SSTAT2[0x0]
SSTAT3[0x0] PERRDIAG[0xc0]:(HIPERR|HIZERO)
SIMODE1[0xac]:(ENSCSIPERR|ENBUSFREE|ENSCSIRST|ENSELTIMO)
LQISTAT0[0x0] LQISTAT1[0x0] LQISTAT2[0x0] LQOSTAT0[0x0]
LQOSTAT1[0x0] LQOSTAT2[0x0]

SCB Count = 4 CMDS_PENDING = 1 LASTSCB 0xffff CURRSCB 0x3 NEXTSCB 0x0
qinstart = 3214 qinfifonext = 3214
QINFIFO:
WAITING_TID_QUEUES:
Pending list:
  3 FIFO_USE[0x0] SCB_CONTROL[0x40]:(DISCENB) SCB_SCSIID[0x47]
Total 1
Kernel Free SCB list: 2 1 0
Sequencer Complete DMA-inprog list:
Sequencer Complete list:
Sequencer DMA-Up and Complete list:

scsi2: FIFO0 Free, LONGJMP == 0x80ff, SCB 0x0
SEQIMODE[0x3f]:(ENCFG4TCMD|ENCFG4ICMD|ENCFG4TSTAT|ENCFG4ISTAT|ENCFG4DATA|ENSAVEPTRS)
SEQINTSRC[0x0] DFCNTRL[0x0] DFSTATUS[0x89]:(FIFOEMP|HDONE|PRELOAD_AVAIL)
SG_CACHE_SHADOW[0x2]:(LAST_SEG) SG_STATE[0x0] DFFSXFRCTL[0x0]
SOFFCNT[0x0] MDFFSTAT[0x5]:(FIFOFREE|DLZERO) SHADDR = 0x00, SHCNT = 0x0
HADDR = 0x00, HCNT = 0x0 CCSGCTL[0x10]:(SG_CACHE_AVAIL)
scsi2: FIFO1 Active, LONGJMP == 0x81d7, SCB 0x3
SEQIMODE[0x3f]:(ENCFG4TCMD|ENCFG4ICMD|ENCFG4TSTAT|ENCFG4ISTAT|ENCFG4DATA|ENSAVEPTRS)
SEQINTSRC[0x0] DFCNTRL[0x4]:(DIRECTION) DFSTATUS[0x88]:(HDONE|PRELOAD_AVAIL)
SG_CACHE_SHADOW[0x2]:(LAST_SEG) SG_STATE[0x0] DFFSXFRCTL[0x0]
SOFFCNT[0x0] MDFFSTAT[0xc]:(DLZERO|SHVALID) SHADDR = 0x00, SHCNT = 0x6
HADDR = 0x00, HCNT = 0x0 CCSGCTL[0x10]:(SG_CACHE_AVAIL)
LQIN: 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0
0x0 0x0
scsi2: LQISTATE = 0x0, LQOSTATE = 0x0, OPTIONMODE = 0x52
scsi2: OS_SPACE_CNT = 0x20 MAXCMDCNT = 0x0

SIMODE0[0xc]:(ENOVERRUN|ENIOERR)
CCSCBCTL[0x4]:(CCSCBDIR)
scsi2: REG0 == 0x3, SINDEX = 0x1c0, DINDEX = 0x10a
scsi2: SCBPTR == 0x3, SCB_NEXT == 0xff00, SCB_NEXT2 == 0xffc3
CDB 0 0 0 0 0 0
STACK: 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0
<<<<<<<<<<<<<<<<< Dump Card State Ends >>>>>>>>>>>>>>>>>>
DevQ(0:4:0): 0 waiting
scsi2:0:4:0: Device is active, asserting ATN
Recovery code sleeping
(scsi2:A:4:0): Abort Message Sent
(scsi2:A:4:0): SCB 3 - Abort Tag Completed.
Recovery SCB completes
found == 0x1
Recovery code awake

Burn of iso in k3b starts out OK but halfway through write fails with following
message:

/usr/bin/cdrecord: Input/output error. write_g1: scsi sendcmd: no error
CDB: 2A 00 00 02 28 4F 00 00 1F 00
status: 0x2 (CHECK CONDITION)
Sense Bytes: F0 00 03 00 02 28 E5 0A 00 00 00 00 0C 07 00 00
Sense Key: 0x3 Medium Error, Segment 0
Sense Code: 0x0C Qual 0x07 (write error - recovery needed) Fru 0x0
Sense flags: Blk 141541 (valid)
resid: 63488
cmd finished after 0.012s timeout 40s
/usr/bin/cdrecord: A write error occured.
/usr/bin/cdrecord: Please properly read the error message above.
write track data: error after 289568768 bytes
Writing time: 485.250s
Average write speed 7.3x.
Min drive buffer fill was 96%
Fixating...
Fixating time: 79.281s
resid: 4
/usr/bin/cdrecord: fifo had 4625 puts and 4562 gets.
/usr/bin/cdrecord: fifo was 0 times empty and 2834 times full, min fill was 92%.
Last selected write speed: 4x
Max media write speed: 4x
Last actual write speed: 4x
BURN-Free was never needed.

cdrecord comand:
-----------------------
/usr/bin/cdrecord.mmap -v gracetime=2 dev=2,4,0 speed=4 -tao driveropts=burnfree
-eject -overburn -data /home/richard/hoary-preview-live-i386.iso

dmesg message above reappears when write fails.

Reerased in k3b and then tried nautilus:
Tried to burn iso file. Nautilus first blanks cd-rw
During erase following scsi errors show up in dmesg
scsi2:0:4:0: Attempting to abort cmd cc111c80: 0x0 0x0 0x0 0x0 0x0 0x0
scsi2:0:4:0: Command found on device queue
scsi2:0:4:0: Attempting to abort cmd cc111c80: 0x1e 0x0 0x0 0x0 0x0 0x0
scsi2: At time of recovery, card was not paused
>>>>>>>>>>>>>>>>>> Dump Card State Begins <<<<<<<<<<<<<<<<<
scsi2: Dumping Card State at program address 0x197 Mode 0x11
Card was paused
HS_MAILBOX[0x0] INTCTL[0x80]:(SWTMINTMASK) SEQINTSTAT[0x0]
SAVED_MODE[0x11] DFFSTAT[0x19]:(CURRFIFO_1|FIFO0FREE)
SCSISIGI[0x84]:(P_COMMAND|BSYI) SCSIPHASE[0x0] SCSIBUS[0x0]
LASTPHASE[0x80]:(P_COMMAND) SCSISEQ0[0x0] SCSISEQ1[0x12]:(ENAUTOATNP|ENRSELI)
SEQCTL0[0x0] SEQINTCTL[0x0] SEQ_FLAGS[0x0] SEQ_FLAGS2[0x0]
SSTAT0[0x0] SSTAT1[0x8]:(BUSFREE) SSTAT2[0x0] SSTAT3[0x0]
PERRDIAG[0xc0]:(HIPERR|HIZERO)
SIMODE1[0xac]:(ENSCSIPERR|ENBUSFREE|ENSCSIRST|ENSELTIMO)
LQISTAT0[0x0] LQISTAT1[0x0] LQISTAT2[0x0] LQOSTAT0[0x0]
LQOSTAT1[0x0] LQOSTAT2[0x0]

SCB Count = 4 CMDS_PENDING = 1 LASTSCB 0xffff CURRSCB 0x3 NEXTSCB 0x0
qinstart = 13641 qinfifonext = 13641
QINFIFO:
WAITING_TID_QUEUES:
Pending list:
  3 FIFO_USE[0x0] SCB_CONTROL[0x40]:(DISCENB) SCB_SCSIID[0x47]
Total 1
Kernel Free SCB list: 2 1 0
Sequencer Complete DMA-inprog list:
Sequencer Complete list:
Sequencer DMA-Up and Complete list:

scsi2: FIFO0 Free, LONGJMP == 0x80ff, SCB 0x0
SEQIMODE[0x3f]:(ENCFG4TCMD|ENCFG4ICMD|ENCFG4TSTAT|ENCFG4ISTAT|ENCFG4DATA|ENSAVEPTRS)
SEQINTSRC[0x0] DFCNTRL[0x0] DFSTATUS[0x89]:(FIFOEMP|HDONE|PRELOAD_AVAIL)
SG_CACHE_SHADOW[0x2]:(LAST_SEG) SG_STATE[0x0] DFFSXFRCTL[0x0]
SOFFCNT[0x0] MDFFSTAT[0x5]:(FIFOFREE|DLZERO) SHADDR = 0x00, SHCNT = 0x0
HADDR = 0x00, HCNT = 0x0 CCSGCTL[0x10]:(SG_CACHE_AVAIL)
scsi2: FIFO1 Active, LONGJMP == 0x81d7, SCB 0x3
SEQIMODE[0x3f]:(ENCFG4TCMD|ENCFG4ICMD|ENCFG4TSTAT|ENCFG4ISTAT|ENCFG4DATA|ENSAVEPTRS)
SEQINTSRC[0x0] DFCNTRL[0x4]:(DIRECTION) DFSTATUS[0x89]:(FIFOEMP|HDONE|PRELOAD_AVAIL)
SG_CACHE_SHADOW[0x3]:(LAST_SEG_DONE|LAST_SEG) SG_STATE[0x0]
DFFSXFRCTL[0x0] SOFFCNT[0x0] MDFFSTAT[0x14]:(DLZERO|LASTSDONE)
SHADDR = 0x06, SHCNT = 0x0 HADDR = 0x00, HCNT = 0x0
CCSGCTL[0x10]:(SG_CACHE_AVAIL)
LQIN: 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0
0x0 0x0
scsi2: LQISTATE = 0x0, LQOSTATE = 0x0, OPTIONMODE = 0x52
scsi2: OS_SPACE_CNT = 0x20 MAXCMDCNT = 0x0
SIMODE0[0xc]:(ENOVERRUN|ENIOERR)
CCSCBCTL[0x4]:(CCSCBDIR)
scsi2: REG0 == 0x3, SINDEX = 0x1c0, DINDEX = 0x10a
scsi2: SCBPTR == 0x3, SCB_NEXT == 0xffc0, SCB_NEXT2 == 0xffee
CDB 1e 0 0 0 0 0
STACK: 0xc9 0x0 0x0 0x0 0x0 0x0 0x0 0x0
<<<<<<<<<<<<<<<<< Dump Card State Ends >>>>>>>>>>>>>>>>>>
DevQ(0:4:0): 0 waiting
scsi2:0:4:0: Device is active, asserting ATN
Recovery code sleeping
Recovery SCB completes
Recovery code awake
cdrom: This disc doesn't have any tracks I recognize!
scsi: unknown opcode 0xe9
scsi: unknown opcode 0xed
scsi: unknown opcode 0x01
scsi2:0:4:0: Attempting to abort cmd e699be00: 0x0 0x0 0x0 0x0 0x0 0x0
scsi2: At time of recovery, card was not paused
>>>>>>>>>>>>>>>>>> Dump Card State Begins <<<<<<<<<<<<<<<<<
scsi2: Dumping Card State at program address 0xca Mode 0x33
Card was paused
HS_MAILBOX[0x0] INTCTL[0x80]:(SWTMINTMASK) SEQINTSTAT[0x0]
SAVED_MODE[0x11] DFFSTAT[0x33]:(CURRFIFO_NONE|FIFO0FREE|FIFO1FREE)
SCSISIGI[0xb6]:(P_MESGOUT|REQI|BSYI|ATNI) SCSIPHASE[0x4]:(MSG_OUT_PHASE)
SCSIBUS[0xc0] LASTPHASE[0xa0]:(P_MESGOUT) SCSISEQ0[0x0]
SCSISEQ1[0x12]:(ENAUTOATNP|ENRSELI) SEQCTL0[0x0] SEQINTCTL[0x0]
SEQ_FLAGS[0x40]:(NO_CDB_SENT) SEQ_FLAGS2[0x0] SSTAT0[0x2]:(SPIORDY)
SSTAT1[0x19]:(REQINIT|BUSFREE|PHASEMIS) SSTAT2[0x0]
SSTAT3[0x0] PERRDIAG[0xc0]:(HIPERR|HIZERO)
SIMODE1[0xac]:(ENSCSIPERR|ENBUSFREE|ENSCSIRST|ENSELTIMO)
LQISTAT0[0x0] LQISTAT1[0x0] LQISTAT2[0x0] LQOSTAT0[0x0]
LQOSTAT1[0x0] LQOSTAT2[0x0]

SCB Count = 4 CMDS_PENDING = 1 LASTSCB 0xffff CURRSCB 0x3 NEXTSCB 0x0
qinstart = 14735 qinfifonext = 14735
QINFIFO:
WAITING_TID_QUEUES:
Pending list:
  3 FIFO_USE[0x0] SCB_CONTROL[0x40]:(DISCENB) SCB_SCSIID[0x47]
Total 1
Kernel Free SCB list: 2 1 0
Sequencer Complete DMA-inprog list:
Sequencer Complete list:
Sequencer DMA-Up and Complete list:

scsi2: FIFO0 Free, LONGJMP == 0x80ff, SCB 0x0
SEQIMODE[0x3f]:(ENCFG4TCMD|ENCFG4ICMD|ENCFG4TSTAT|ENCFG4ISTAT|ENCFG4DATA|ENSAVEPTRS)
SEQINTSRC[0x0] DFCNTRL[0x0] DFSTATUS[0x89]:(FIFOEMP|HDONE|PRELOAD_AVAIL)
SG_CACHE_SHADOW[0x2]:(LAST_SEG) SG_STATE[0x0] DFFSXFRCTL[0x0]
SOFFCNT[0x0] MDFFSTAT[0x5]:(FIFOFREE|DLZERO) SHADDR = 0x00, SHCNT = 0x0
HADDR = 0x00, HCNT = 0x0 CCSGCTL[0x10]:(SG_CACHE_AVAIL)
scsi2: FIFO1 Free, LONGJMP == 0x81d7, SCB 0x3
SEQIMODE[0x3f]:(ENCFG4TCMD|ENCFG4ICMD|ENCFG4TSTAT|ENCFG4ISTAT|ENCFG4DATA|ENSAVEPTRS)
SEQINTSRC[0x0] DFCNTRL[0x4]:(DIRECTION) DFSTATUS[0x89]:(FIFOEMP|HDONE|PRELOAD_AVAIL)
SG_CACHE_SHADOW[0x2]:(LAST_SEG) SG_STATE[0x0] DFFSXFRCTL[0x0]
SOFFCNT[0x0] MDFFSTAT[0x5]:(FIFOFREE|DLZERO) SHADDR = 0x00, SHCNT = 0x0
HADDR = 0x00, HCNT = 0x0 CCSGCTL[0x10]:(SG_CACHE_AVAIL)
LQIN: 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0
0x0 0x0
scsi2: LQISTATE = 0x0, LQOSTATE = 0x0, OPTIONMODE = 0x52
scsi2: OS_SPACE_CNT = 0x20 MAXCMDCNT = 0x0

SIMODE0[0xc]:(ENOVERRUN|ENIOERR)
CCSCBCTL[0x4]:(CCSCBDIR)
scsi2: REG0 == 0x3, SINDEX = 0x10a, DINDEX = 0x10a
scsi2: SCBPTR == 0x3, SCB_NEXT == 0xffc0, SCB_NEXT2 == 0xffee
CDB 0 0 0 0 0 0
STACK: 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0
<<<<<<<<<<<<<<<<< Dump Card State Ends >>>>>>>>>>>>>>>>>>
DevQ(0:4:0): 0 waiting
scsi2:0:4:0: Device is active, asserting ATN
(scsi2:A:4:0): Abort Message Sent
Recovery code sleeping
(scsi2:A:4:0): SCB 3 - Abort Tag Completed.
Recovery SCB completes
found == 0x1
Recovery code awake
scsi: unknown opcode 0xf5

Nautilus then starts writing and completes successfully.

On other occasions nautilus also fails and similar dmesg messages as above appear

lsmod shows
Module Size Used by
nls_cp437 5824 0
isofs 36700 0
udf 89412 0
proc_intf 4260 0
freq_table 4320 0
cpufreq_userspace 6240 0
cpufreq_ondemand 6728 0
cpufreq_powersave 1856 0
video 16196 0
sony_acpi 6152 0
pcc_acpi 11232 0
button 6704 0
battery 10212 0
container 4544 0
ac 4900 0
capifs 5960 1
ipv6 257760 10
af_packet 22504 2
sg 38656 0
ohci1394 34916 0
emu10k1_gp 3872 0
gameport 4864 1 emu10k1_gp
usblp 12992 0
snd_emu10k1 98532 2
snd_rawmidi 25024 1 snd_emu10k1
snd_seq_device 8716 2 snd_emu10k1,snd_rawmidi
snd_ac97_codec 74336 1 snd_emu10k1
snd_pcm_oss 52836 1
snd_mixer_oss 19968 2 snd_pcm_oss
snd_pcm 95780 3 snd_emu10k1,snd_ac97_codec,snd_pcm_oss
snd_timer 25572 1 snd_pcm
snd_page_alloc 9988 2 snd_emu10k1,snd_pcm
tsdev 7776 0
snd_util_mem 4640 1 snd_emu10k1
snd_hwdep 9700 1 snd_emu10k1
snd 56580 9
snd_emu10k1,snd_rawmidi,snd_seq_device,snd_ac97_codec,snd_pcm_oss,snd_mixer_oss,snd_pcm,snd_timer,snd_hwdep
soundcore 10400 3 snd
i2c_i801 8652 0
i2c_core 22720 1 i2c_i801
ahci 11076 0
piix 10884 1
hw_random 5620 0
usbhid 32384 0
ehci_hcd 33252 0
uhci_hcd 33488 0
usbcore 119480 5 usblp,usbhid,ehci_hcd,uhci_hcd
pciehp 96556 0
shpchp 99620 0
pci_hotplug 33980 2 pciehp,shpchp
floppy 59472 0
pcspkr 3788 0
rtc 12776 0
md 48112 0
dm_mod 60480 1
capability 4872 0
commoncap 8032 1 capability
nvidia 3471932 12
parport_pc 37924 1
lp 11464 0
parport 37352 2 parport_pc,lp
evdev 9600 0
sbp2 24008 0
ieee1394 108856 2 ohci1394,sbp2
ide_generic 1536 0
ide_disk 20896 0
ide_cd 42052 0
ide_core 129656 4 piix,ide_generic,ide_disk,ide_cd
mousedev 11612 1
psmouse 21736 0
sk98lin 204168 1
ext3 138664 5
jbd 63544 1 ext3
mbcache 8452 1 ext3
sr_mod 17444 0
cdrom 40476 2 ide_cd,sr_mod
sd_mod 18080 7
aic79xx 310556 14
ata_piix 9412 0
libata 49508 2 ahci,ata_piix
scsi_mod 128288 7 sg,ahci,sbp2,sr_mod,sd_mod,aic79xx,libata
unix 28692 775
thermal 13672 0
processor 23400 1 thermal
fan 4612 0
fbcon 37856 0
font 8416 1 fbcon
bitblit 5696 1 fbcon
vesafb 6948 0
cfbcopyarea 4032 1 vesafb
cfbimgblt 3136 1 vesafb
cfbfillrect 3712 1 vesafb

lspci -v shows
0000:00:00.0 Host bridge: Intel Corp. 925X Memory Controller Hub (rev 04)
        Subsystem: Intel Corp.: Unknown device 4356
        Flags: bus master, fast devsel, latency 0
        Capabilities: [e0] #09 [2109]

0000:00:01.0 PCI bridge: Intel Corp. 925X PCI Express Root Port (rev 04)
(prog-if 00 [Normal decode])
        Flags: bus master, fast devsel, latency 0
        Bus: primary=00, secondary=01, subordinate=01, sec-latency=0
        Memory behind bridge: fa300000-fe3fffff
        Prefetchable memory behind bridge: bf900000-df9fffff
        Capabilities: [88] #0d [0000]
        Capabilities: [80] Power Management version 2
        Capabilities: [90] Message Signalled Interrupts: 64bit- Queue=0/0 Enable-
        Capabilities: [a0] #10 [0141]

0000:00:1c.0 PCI bridge: Intel Corp. 82801FB/FBM/FR/FW/FRW (ICH6 Family) PCI
Express Port 1 (rev 03) (prog-if 00 [Normal decode])
        Flags: bus master, fast devsel, latency 0
        Bus: primary=00, secondary=05, subordinate=05, sec-latency=0
        Memory behind bridge: fe700000-fe7fffff
        Prefetchable memory behind bridge: 00000000dfd00000-00000000dfd00000
        Capabilities: [40] #10 [0141]
        Capabilities: [80] Message Signalled Interrupts: 64bit- Queue=0/0 Enable-
        Capabilities: [90] #0d [0000]
        Capabilities: [a0] Power Management version 2

0000:00:1c.1 PCI bridge: Intel Corp. 82801FB/FBM/FR/FW/FRW (ICH6 Family) PCI
Express Port 2 (rev 03) (prog-if 00 [Normal decode])
        Flags: bus master, fast devsel, latency 0
        Bus: primary=00, secondary=04, subordinate=04, sec-latency=0
        I/O behind bridge: 00009000-00009fff
        Memory behind bridge: fe600000-fe6fffff
        Prefetchable memory behind bridge: 00000000dfc00000-00000000dfc00000
        Capabilities: [40] #10 [0141]
        Capabilities: [80] Message Signalled Interrupts: 64bit- Queue=0/0 Enable-
        Capabilities: [90] #0d [0000]
        Capabilities: [a0] Power Management version 2

0000:00:1c.2 PCI bridge: Intel Corp. 82801FB/FBM/FR/FW/FRW (ICH6 Family) PCI
Express Port 3 (rev 03) (prog-if 00 [Normal decode])
        Flags: bus master, fast devsel, latency 0
        Bus: primary=00, secondary=03, subordinate=03, sec-latency=0
        Memory behind bridge: fe500000-fe5fffff
        Prefetchable memory behind bridge: 00000000dfb00000-00000000dfb00000
        Capabilities: [40] #10 [0141]
        Capabilities: [80] Message Signalled Interrupts: 64bit- Queue=0/0 Enable-
        Capabilities: [90] #0d [0000]
        Capabilities: [a0] Power Management version 2

0000:00:1c.3 PCI bridge: Intel Corp. 82801FB/FBM/FR/FW/FRW (ICH6 Family) PCI
Express Port 4 (rev 03) (prog-if 00 [Normal decode])
        Flags: bus master, fast devsel, latency 0
        Bus: primary=00, secondary=02, subordinate=02, sec-latency=0
        Memory behind bridge: fe400000-fe4fffff
        Prefetchable memory behind bridge: 00000000dfa00000-00000000dfa00000
        Capabilities: [40] #10 [0141]
        Capabilities: [80] Message Signalled Interrupts: 64bit- Queue=0/0 Enable-
        Capabilities: [90] #0d [0000]
        Capabilities: [a0] Power Management version 2

0000:00:1d.0 USB Controller: Intel Corp. 82801FB/FBM/FR/FW/FRW (ICH6 Family) USB
UHCI #1 (rev 03) (prog-if 00 [UHCI])
        Subsystem: Intel Corp.: Unknown device 4356
        Flags: bus master, medium devsel, latency 0, IRQ 23
        I/O ports at cc00 [size=32]

0000:00:1d.1 USB Controller: Intel Corp. 82801FB/FBM/FR/FW/FRW (ICH6 Family) USB
UHCI #2 (rev 03) (prog-if 00 [UHCI])
        Subsystem: Intel Corp.: Unknown device 4356
        Flags: bus master, medium devsel, latency 0, IRQ 19
        I/O ports at d000 [size=32]

0000:00:1d.2 USB Controller: Intel Corp. 82801FB/FBM/FR/FW/FRW (ICH6 Family) USB
UHCI #3 (rev 03) (prog-if 00 [UHCI])
        Subsystem: Intel Corp.: Unknown device 4356
        Flags: bus master, medium devsel, latency 0, IRQ 18
        I/O ports at d400 [size=32]

0000:00:1d.3 USB Controller: Intel Corp. 82801FB/FBM/FR/FW/FRW (ICH6 Family) USB
UHCI #4 (rev 03) (prog-if 00 [UHCI])
        Subsystem: Intel Corp.: Unknown device 4356
        Flags: bus master, medium devsel, latency 0, IRQ 16
        I/O ports at d800 [size=32]

0000:00:1d.7 USB Controller: Intel Corp. 82801FB/FBM/FR/FW/FRW (ICH6 Family)
USB2 EHCI Controller (rev 03) (prog-if 20 [EHCI])
        Subsystem: Intel Corp.: Unknown device 4356
        Flags: bus master, medium devsel, latency 0, IRQ 23
        Memory at febff800 (32-bit, non-prefetchable) [size=1K]
        Capabilities: [50] Power Management version 2
        Capabilities: [58] #0a [20a0]

0000:00:1e.0 PCI bridge: Intel Corp. 82801 PCI Bridge (rev d3) (prog-if 01
[Subtractive decode])
        Flags: bus master, fast devsel, latency 0
        Bus: primary=00, secondary=06, subordinate=06, sec-latency=32
        I/O behind bridge: 0000a000-0000bfff
        Memory behind bridge: fe800000-feafffff
        Prefetchable memory behind bridge: 00000000dfe00000-00000000dfe00000
        Capabilities: [50] #0d [0000]

0000:00:1f.0 ISA bridge: Intel Corp. 82801FB/FR (ICH6/ICH6R) LPC Interface
Bridge (rev 03)
        Subsystem: Intel Corp.: Unknown device 4356
        Flags: bus master, medium devsel, latency 0

0000:00:1f.1 IDE interface: Intel Corp. 82801FB/FBM/FR/FW/FRW (ICH6 Family) IDE
Controller (rev 03) (prog-if 8a [Master SecP PriP])
        Subsystem: Intel Corp.: Unknown device 4356
        Flags: bus master, medium devsel, latency 0, IRQ 18
        I/O ports at <unassigned>
        I/O ports at <unassigned>
        I/O ports at <unassigned>
        I/O ports at <unassigned>
        I/O ports at ffa0 [size=16]

0000:00:1f.2 IDE interface: Intel Corp. 82801FR/FRW (ICH6R/ICH6RW) SATA
Controller (rev 03) (prog-if 8f [Master SecP SecO PriP PriO])
        Subsystem: Intel Corp.: Unknown device 4356
        Flags: bus master, 66MHz, medium devsel, latency 0, IRQ 19
        I/O ports at ec00 [size=8]
        I/O ports at e800 [size=4]
        I/O ports at e400 [size=8]
        I/O ports at e000 [size=4]
        I/O ports at dc00 [size=16]
        Memory at febffc00 (32-bit, non-prefetchable) [size=1K]
        Capabilities: [70] Power Management version 2

0000:00:1f.3 SMBus: Intel Corp. 82801FB/FBM/FR/FW/FRW (ICH6 Family) SMBus
Controller (rev 03)
        Subsystem: Intel Corp.: Unknown device 4356
        Flags: medium devsel, IRQ 10
        I/O ports at c800 [size=32]

0000:01:00.0 VGA compatible controller: nVidia Corporation: Unknown device 00fb
(rev a2) (prog-if 00 [VGA])
        Subsystem: Giga-byte Technology: Unknown device 3121
        Flags: bus master, fast devsel, latency 0, IRQ 16
        Memory at fd000000 (32-bit, non-prefetchable) [size=16M]
        Memory at c0000000 (32-bit, prefetchable) [size=256M]
        Memory at fc000000 (32-bit, non-prefetchable) [size=16M]
        Expansion ROM at fe3e0000 [disabled] [size=128K]
        Capabilities: [60] Power Management version 2
        Capabilities: [68] Message Signalled Interrupts: 64bit+ Queue=0/0 Enable-
        Capabilities: [78] #10 [0011]

0000:04:00.0 Ethernet controller: Marvell Technology Group Ltd.: Unknown device
4361 (rev 17)
        Subsystem: Intel Corp.: Unknown device 3063
        Flags: bus master, fast devsel, latency 0, IRQ 17
        Memory at fe6fc000 (64-bit, non-prefetchable) [size=16K]
        I/O ports at 9800 [size=256]
        Expansion ROM at fe6c0000 [disabled] [size=128K]
        Capabilities: [48] Power Management version 2
        Capabilities: [50] Vital Product Data
        Capabilities: [5c] Message Signalled Interrupts: 64bit+ Queue=0/1 Enable-
        Capabilities: [e0] #10 [0011]

0000:06:02.0 SCSI storage controller: Adaptec ASC-39320A U320 (rev 10)
        Subsystem: Adaptec: Unknown device 0040
        Flags: bus master, 66MHz, slow devsel, latency 32, IRQ 18
        I/O ports at b000 [disabled] [size=256]
        Memory at feafc000 (64-bit, non-prefetchable) [size=8K]
        I/O ports at a800 [disabled] [size=256]
        Expansion ROM at fe980000 [disabled] [size=512K]
        Capabilities: [dc] Power Management version 2
        Capabilities: [a0] Message Signalled Interrupts: 64bit+ Queue=0/1 Enable-
        Capabilities: [94]
0000:06:02.1 SCSI storage controller: Adaptec ASC-39320A U320 (rev 10)
        Subsystem: Adaptec: Unknown device 0040
        Flags: bus master, 66MHz, slow devsel, latency 32, IRQ 19
        I/O ports at b800 [disabled] [size=256]
        Memory at feafe000 (64-bit, non-prefetchable) [size=8K]
        I/O ports at b400 [disabled] [size=256]
        Expansion ROM at fea00000 [disabled] [size=512K]
        Capabilities: [dc] Power Management version 2
        Capabilities: [a0] Message Signalled Interrupts: 64bit+ Queue=0/1 Enable-
        Capabilities: [94]
0000:06:03.0 Multimedia audio controller: Creative Labs SB Audigy (rev 04)
        Subsystem: Creative Labs: Unknown device 1007
        Flags: bus master, medium devsel, latency 32, IRQ 19
        I/O ports at ac00 [size=64]
        Capabilities: [dc] Power Management version 2

0000:06:03.1 Input device controller: Creative Labs SB Audigy MIDI/Game port
(rev 04)
        Subsystem: Creative Labs SB Audigy MIDI/Game Port
        Flags: bus master, medium devsel, latency 32
        I/O ports at bc00 [size=8]
        Capabilities: [dc] Power Management version 2

0000:06:03.2 FireWire (IEEE 1394): Creative Labs SB Audigy FireWire Port (rev
04) (prog-if 10 [OHCI])
        Subsystem: Creative Labs SB Audigy FireWire Port
        Flags: bus master, medium devsel, latency 32, IRQ 18
        Memory at feafb800 (32-bit, non-prefetchable) [size=2K]
        Memory at feaf4000 (32-bit, non-prefetchable) [size=16K]
        Capabilities: [44] Power Management version 2

0000:06:05.0 FireWire (IEEE 1394): Lucent Microelectronics FW323 (rev 61)
(prog-if 10 [OHCI])
        Subsystem: Intel Corp.: Unknown device 4356
        Flags: bus master, medium devsel, latency 32, IRQ 17
        Memory at feafa000 (32-bit, non-prefetchable) [size=4K]
        Capabilities: [44] Power Management version 2

[Richard Kleeman (kleeman)]

I should have added that I have a Plextor scsi cdburner 40/4

[Matt Zimmerman (mdz)]

I also experience problems burning to an sg device (in my case a USB writer) on
Hoary. The writer works perfectly with DVD media and growisofs/n-c-b, so it's
not clear whether this is a kernel problem or a cdrecord problem, or both.

[Richard Kleeman (kleeman)]

I remember reading sometime back in an article by Joe Barr on Newsforge of a
MAJOR disagreement between Torvalds and Schilling (the author of cdrecord)
over the state of the cdrecord code (Torvald's gripe) and the way it interacted
with the scsi parts of the kernel (Schilling's gripe). Perhaps there is a
connection.

[Ralph Corderoy (ralph-inputplus)]

Created an attachment (id=3084)
Output of cdrecord failing to write a CD-R.

I'm also getting similar errors when trying to use cdrecord on this
Ubuntu installation.

    $ apt-show-versions -p cdrecord
    cdrecord/unknown uptodate 4:2.0+a38-1ubuntu4
    $

The hardware is identical to before trampling an old Red Hat
installation with Ubuntu. cdrecord was used daily then for backups with
no problems. As I'm now without daily backups I'd like to get it
working.

[Ralph Corderoy (ralph-inputplus)]

After two cdrecord failures I've had one success. This was achieved by
booting using the `Ubuntu, kernel 2.6.10-5-386 (recovery mode)' grub
menu item to get a root shell and doing the cdrecord from there. There
were no other differences.

So this may be a workaround; it would be nice if someone else confirms
it works for them.

This suggests the problem may be part of Gnome, e.g. HAL or
gnome-volume-manager(1), interfering with the SCSI device once cdrecord
starts to write to the CD because it thinks a CD is now present instead
of a blank CD-R. (If I knew a safe way to kill off all the various bits
of Gnome that have something to do with this I'd give it a try.)

[Chuck Short (zulcss)]

Does this work in breezy I would like to close this bug since there has been
nothing done for a couple of months. Please re-open if you are still
experiencing this problem

[Richard Kleeman (kleeman)]

Unfortunately it is still present in breezy.

Inserted cdrw into cdrw scsi drive and wrote an iso to the disk using nautilus.
cdrw went offline after erasure was completed. This meant that the whole system
needed a reboot.
The dmesg output follows:

[4319535.861000] scsi: unknown opcode 0xe9
[4319535.861000] scsi: unknown opcode 0xed
[4319538.762000] scsi: unknown opcode 0x01
[4319598.762000] scsi4:0:4:0: Attempting to abort cmd ea680380: 0x0 0x0 0x0 0x0
0x0 0x0
[4319598.762000] scsi4: At time of recovery, card was not paused
[4319598.762000] >>>>>>>>>>>>>>>>>> Dump Card State Begins <<<<<<<<<<<<<<<<<
[4319598.762000] scsi4: Dumping Card State at program address 0x19d Mode 0x33
[4319598.762000] Card was paused
[4319598.762000] HS_MAILBOX[0x0] INTCTL[0x80]:(SWTMINTMASK)
[4319598.762000] SEQINTSTAT[0x0] SAVED_MODE[0x11]
[4319598.762000] DFFSTAT[0x33]:(CURRFIFO_NONE|FIFO0FREE|FIFO1FREE)
[4319598.762000] SCSISIGI[0xb6]:(P_MESGOUT|REQI|BSYI|ATNI)
[4319598.762000] SCSIPHASE[0x4]:(MSG_OUT_PHASE) SCSIBUS[0xc0]
[4319598.762000] LASTPHASE[0x1]:(P_DATAOUT|P_BUSFREE)
[4319598.762000] SCSISEQ0[0x0] SCSISEQ1[0x12]:(ENAUTOATNP|ENRSELI)
[4319598.762000] SEQCTL0[0x0] SEQINTCTL[0x0] SEQ_FLAGS[0x40]:(NO_CDB_SENT)
[4319598.762000] SEQ_FLAGS2[0x0] SSTAT0[0x2]:(SPIORDY)
[4319598.762000] SSTAT1[0x19]:(REQINIT|BUSFREE|PHASEMIS)
[4319598.762000] SSTAT2[0x0] SSTAT3[0x0] PERRDIAG[0xc0]:(HIPERR|HIZERO)
[4319598.762000] SIMODE1[0xac]:(ENSCSIPERR|ENBUSFREE|ENSCSIRST|ENSELTIMO)
[4319598.762000] LQISTAT0[0x0] LQISTAT1[0x0] LQISTAT2[0x0]
[4319598.762000] LQOSTAT0[0x0] LQOSTAT1[0x0] LQOSTAT2[0x0]
[4319598.762000]
[4319598.762000] SCB Count = 4 CMDS_PENDING = 1 LASTSCB 0xffff CURRSCB 0x3
NEXTSCB 0x0
[4319598.762000] qinstart = 53133 qinfifonext = 53133
[4319598.762000] QINFIFO:
[4319598.762000] WAITING_TID_QUEUES:
[4319598.762000] Pending list:
[4319598.762000] 3 FIFO_USE[0x0] SCB_CONTROL[0x40]:(DISCENB)
[4319598.762000] SCB_SCSIID[0x47]
[4319598.762000] Total 1
[4319598.762000] Kernel Free SCB list: 2 1 0
[4319598.762000] Sequencer Complete DMA-inprog list:
[4319598.762000] Sequencer Complete list:
[4319598.762000] Sequencer DMA-Up and Complete list:
[4319598.762000]
[4319598.762000] scsi4: FIFO0 Free, LONGJMP == 0x80ff, SCB 0x0
[4319598.762000]
SEQIMODE[0x3f]:(ENCFG4TCMD|ENCFG4ICMD|ENCFG4TSTAT|ENCFG4ISTAT|ENCFG4DATA|ENSAVEPTRS)
[4319598.762000] SEQINTSRC[0x0] DFCNTRL[0x0]
DFSTATUS[0x89]:(FIFOEMP|HDONE|PRELOAD_AVAIL)
[4319598.762000] SG_CACHE_SHADOW[0x2]:(LAST_SEG) SG_STATE[0x0]
[4319598.762000] DFFSXFRCTL[0x0] SOFFCNT[0x0] MDFFSTAT[0x5]:(FIFOFREE|DLZERO)
[4319598.762000] SHADDR = 0x00, SHCNT = 0x0 HADDR = 0x00, HCNT = 0x0
[4319598.762000] CCSGCTL[0x10]:(SG_CACHE_AVAIL)
[4319598.762000] scsi4: FIFO1 Free, LONGJMP == 0x81d7, SCB 0x3
[4319598.762000]
SEQIMODE[0x3f]:(ENCFG4TCMD|ENCFG4ICMD|ENCFG4TSTAT|ENCFG4ISTAT|ENCFG4DATA|ENSAVEPTRS)
[4319598.762000] SEQINTSRC[0x0] DFCNTRL[0x4]:(DIRECTION)
[4319598.762000] DFSTATUS[0x89]:(FIFOEMP|HDONE|PRELOAD_AVAIL)
[4319598.762000] SG_CACHE_SHADOW[0x2]:(LAST_SEG) SG_STATE[0x0]
[4319598.762000] DFFSXFRCTL[0x0] SOFFCNT[0x0] MDFFSTAT[0x5]:(FIFOFREE|DLZERO)
[4319598.762000] SHADDR = 0x00, SHCNT = 0x0 HADDR = 0x00, HCNT = 0x0
[4319598.762000] CC...

[Ben Collins (ben-collins)]

This bug has been flagged because it is old and possibly inactive. It may or may
not be fixed in the latest release (Breezy Badger 5.10). It is being marked as
"NEEDSINFO". In two weeks time, if the bug is not updated back to "NEW" and
validated against Breezy, it will be closed.

This is needed in order to help manage the current bug list for the kernel. We
would like to fix all bugs, but need users to test and help with debugging.

If this change was in error for this bug, please respond and make the
appropriate change (or email <email address hidden> if you cannot make the
change).

Thanks for your help.

[Richard Kleeman (kleeman)]

As mentioned above this bug is still present in breezy.

[Ben Collins (ben-collins)]

If possible, please upgrade to Dapper's 2.6.15-7 kernel. If you do not want to
upgrade to Dapper, then you can also wait for the Dapper Flight 2 CD's, which
are due out within the next few days.

Let me know if this bug still exists with this kernel.

[Richard Kleeman (kleeman)]

Confirmed that problem still exists with the 2.6.15-7 kernel. In addition while
testing I had a hard lockup (kernel?) which required a manual power down. If you
would like more detailed information as the kernel stabilizes let me know.
Perhaps a standard test using either nautilus or cdrecord?

[Richard Kleeman (kleeman)]

Created an attachment (id=5225)
Kernel Error messages

[Richard Kleeman (kleeman)]

Problem appears more severe in the 2.6.15-7 kernel than the breezy kernel. As
noted above there was a hard lockup in addition when I placed a cd-rw in the
scsi rw drive and booted the system a whole bunch of rather threatening kernel
error messages were produced (attached).

[Richard Kleeman (kleeman)]

Bug apparently also reported for FC4 here with a 2.6.14 kernel and similar hardware:

https://www.redhat.com/archives/fedora-list/2005-November/msg03095.html

[Ben Collins (ben-collins)]

(In reply to comment #13)
> Problem appears more severe in the 2.6.15-7 kernel than the breezy kernel. As
> noted above there was a hard lockup in addition when I placed a cd-rw in the
> scsi rw drive and booted the system a whole bunch of rather threatening kernel
> error messages were produced (attached).

Which 2.6.15-7 kernel are you using? I'd like to compile a test module for you
(this is aic79xx, correct?)

I think I see the change from upstream where this problem occured, so I want to
revert it and see if it works for you.

[Richard Kleeman (kleeman)]

The kernel version is 2.6.15-7.9 (686 architecture) and the output of

lsmod | grep aic

is

aic79xx 297080 15
scsi_transport_spi 22624 1 aic79xx
scsi_mod 144552 8
sg,sr_mod,sbp2,sd_mod,aic79xx,scsi_transport_spi,ahci,libata

[Ben Collins (ben-collins)]

(In reply to comment #16)
> The kernel version is 2.6.15-7.9 (686 architecture) and the output of

Attaching test module. To use these modules, perform this after downloading it:

$ bunzip2 aic79xx.ko.bz2
$ mv aic79xx.ko /lib/modules/2.6.15-7-686/kernel/drivers/scsi/aic7xxx/
$ depmod -a
$ update-initramfs -u -k 2.6.15-7-686

Then reboot and see if the problem still occurs.

[Ben Collins (ben-collins)]

Created an attachment (id=5238)
aic79xx patch level 22

[Richard Kleeman (kleeman)]

Followed the instructions and rebooted with a cd-rw (written) in the drive. No
longer produced hard lockup however similar kernel error messages were produced
(see below) and the drive was unusable. here are the last 200 lines or so of
dmesg following the insertion of a blank cdrw (nothing occured with nautilus):

[17180937.072000] VFS: busy inodes on changed media.
[17180937.080000] VFS: busy inodes on changed media.
[17180937.092000] VFS: busy inodes on changed media.
[17180937.100000] VFS: busy inodes on changed media.
[17180937.112000] VFS: busy inodes on changed media.
[17180939.124000] VFS: busy inodes on changed media.
[17180939.132000] VFS: busy inodes on changed media.
[17180941.148000] VFS: busy inodes on changed media.
[17180941.156000] VFS: busy inodes on changed media.
[17180943.172000] VFS: busy inodes on changed media.
[17180943.180000] VFS: busy inodes on changed media.
[17180945.196000] VFS: busy inodes on changed media.
[17180945.204000] VFS: busy inodes on changed media.
[17180947.220000] VFS: busy inodes on changed media.
[17180947.228000] VFS: busy inodes on changed media.
[17180949.244000] VFS: busy inodes on changed media.
[17180949.252000] VFS: busy inodes on changed media.
[17180951.268000] VFS: busy inodes on changed media.
[17180951.276000] VFS: busy inodes on changed media.
[17180953.292000] VFS: busy inodes on changed media.
[17180953.300000] VFS: busy inodes on changed media.
[17180955.316000] VFS: busy inodes on changed media.
[17180955.328000] VFS: busy inodes on changed media.
[17180957.340000] VFS: busy inodes on changed media.
[17180957.348000] VFS: busy inodes on changed media.
[17180976.152000] VFS: busy inodes on changed media.
[17180976.168000] VFS: busy inodes on changed media.
[17180976.172000] (scsi4:A:4:0): No or incomplete CDB sent to device.
[17180976.172000] scsi4: Issued Channel A Bus Reset. 1 SCBs aborted
[17180976.388000] (scsi4:A:4:0): No or incomplete CDB sent to device.
[17180976.388000] (scsi4:A:4:0): Protocol violation in Message-in phase.
Attempting to abort.
[17180976.388000] (scsi4:A:4:0): Unexpected busfree in Message-in phase, 1 SCBs
aborted, PRGMCNT == 0x199
[17180976.388000] >>>>>>>>>>>>>>>>>> Dump Card State Begins <<<<<<<<<<<<<<<<<
[17180976.388000] scsi4: Dumping Card State at program address 0x197 Mode 0x11
[17180976.388000] Card was paused
[17180976.388000] HS_MAILBOX[0x0] INTCTL[0x80]:(SWTMINTMASK)
[17180976.388000] SEQINTSTAT[0x0] SAVED_MODE[0x11]
[17180976.388000] DFFSTAT[0x13]:(CURRFIFO_NONE|FIFO0FREE)
[17180976.388000] SCSISIGI[0x0]:(P_DATAOUT) SCSIPHASE[0x0]
[17180976.388000] SCSIBUS[0x0] LASTPHASE[0xe0]:(P_MESGIN)
[17180976.388000] SCSISEQ0[0x0] SCSISEQ1[0x12]:(ENAUTOATNP|ENRSELI)
[17180976.388000] SEQCTL0[0x0] SEQINTCTL[0x0] SEQ_FLAGS[0x40]:(NO_CDB_SENT)
[17180976.388000] SEQ_FLAGS2[0x0] SSTAT0[0x0] SSTAT1[0x8]:(BUSFREE)
[17180976.388000] SSTAT2[0xc0]:(BUSFREE_DFF1) SSTAT3[0x0]
[17180976.388000] PERRDIAG[0xc0]:(HIPERR|HIZERO)
SIMODE1[0xac]:(ENSCSIPERR|ENBUSFREE|ENSCSIRST|ENSELTIMO)
[17180976.388000] LQISTAT0[0x0] LQISTAT1[0x0] LQISTAT2[0x0]
[17180976.388000] LQOSTAT0[0x0] LQOSTAT1[0x0] LQOSTAT2[0x0]
[17180976.388000]
[17180976.388000] SCB Count = 4 CMDS_PENDING = 1 LAS...

[Richard Kleeman (kleeman)]

As a sanity check on the hardware I rebooted into breezy and burnt some music
with serpentine using the same blank cdr. Worked fine (and played fine as well)
with the following error messages:

[4295375.451000] scsi: unknown opcode 0xe9
[4295375.451000] scsi: unknown opcode 0xed
[4295380.198000] scsi: unknown opcode 0x01
[4295389.298000] scsi: unknown opcode 0xf5
[4295641.920000] scsi: unknown opcode 0xeb

[Richard Kleeman (kleeman)]

Problem appears very severe. Hard lockup occured today with the following output
from /var/log/messages.
This issue is a showstopper for my main desktop at present. Do you think it is a
kernel problem?

Dec 15 09:21:03 localhost kernel: [17181972.840000] >>>>>>>>>>>>>>>>>> Dump Card
State Begins <<<<<<<<<<<<<<<<<
Dec 15 09:21:03 localhost kernel: [17181972.840000] scsi4: Dumping Card State at
program address 0x196 Mode 0x11
Dec 15 09:21:03 localhost kernel: [17181972.840000] Card was paused
Dec 15 09:21:03 localhost kernel: [17181972.840000] HS_MAILBOX[0x0]
INTCTL[0x80]:(SWTMINTMASK)
Dec 15 09:21:03 localhost kernel: [17181972.840000] SEQINTSTAT[0x0] SAVED_MODE[0x11]
Dec 15 09:21:03 localhost kernel: [17181972.840000]
DFFSTAT[0x13]:(CURRFIFO_NONE|FIFO0FREE)
Dec 15 09:21:03 localhost kernel: [17181972.840000] SCSISIGI[0x0]:(P_DATAOUT)
SCSIPHASE[0x0]
Dec 15 09:21:03 localhost kernel: [17181972.840000] SCSIBUS[0x0]
LASTPHASE[0xe0]:(P_MESGIN)
Dec 15 09:21:03 localhost kernel: [17181972.840000] SCSISEQ0[0x0]
SCSISEQ1[0x12]:(ENAUTOATNP|ENRSELI)
Dec 15 09:21:03 localhost kernel: [17181972.840000] SEQCTL0[0x0] SEQINTCTL[0x0]
SEQ_FLAGS[0x40]:(NO_CDB_SENT)
Dec 15 09:21:03 localhost kernel: [17181972.840000] SEQ_FLAGS2[0x0] SSTAT0[0x0]
SSTAT1[0x8]:(BUSFREE)
Dec 15 09:21:03 localhost kernel: [17181972.840000] SSTAT2[0xc0]:(BUSFREE_DFF1)
SSTAT3[0x0]
Dec 15 09:21:03 localhost kernel: [17181972.840000]
PERRDIAG[0xc0]:(HIPERR|HIZERO)
SIMODE1[0xac]:(ENSCSIPERR|ENBUSFREE|ENSCSIRST|ENSELTIMO)
Dec 15 09:21:03 localhost kernel: [17181972.840000] LQISTAT0[0x0] LQISTAT1[0x0]
LQISTAT2[0x0]
Dec 15 09:21:03 localhost kernel: [17181972.840000] LQOSTAT0[0x0] LQOSTAT1[0x0]
LQOSTAT2[0x0]
Dec 15 09:21:03 localhost kernel: [17181972.840000]
Dec 15 09:21:03 localhost kernel: [17181972.840000] SCB Count = 4 CMDS_PENDING =
1 LASTSCB 0xffff CURRSCB 0x2 NEXTSCB 0x0
Dec 15 09:21:03 localhost kernel: [17181972.840000] qinstart = 47687 qinfifonext
= 47687
Dec 15 09:21:03 localhost kernel: [17181972.840000] QINFIFO:
Dec 15 09:21:03 localhost kernel: [17181972.840000] WAITING_TID_QUEUES:
Dec 15 09:21:03 localhost kernel: [17181972.840000] Pending list:
Dec 15 09:21:03 localhost kernel: [17181972.840000] Total 0
Dec 15 09:21:03 localhost kernel: [17181972.840000] Kernel Free SCB list: 2 3 1 0
Dec 15 09:21:03 localhost kernel: [17181972.840000] Sequencer Complete
DMA-inprog list:
Dec 15 09:21:03 localhost kernel: [17181972.840000] Sequencer Complete list:
Dec 15 09:21:03 localhost kernel: [17181972.840000] Sequencer DMA-Up and
Complete list:
Dec 15 09:21:03 localhost kernel: [17181972.840000]
Dec 15 09:21:03 localhost kernel: [17181972.840000] scsi4: FIFO0 Free, LONGJMP
== 0x80ff, SCB 0x0
Dec 15 09:21:03 localhost kernel: [17181972.840000]
SEQIMODE[0x3f]:(ENCFG4TCMD|ENCFG4ICMD|ENCFG4TSTAT|ENCFG4ISTAT|ENCFG4DATA|ENSAVEPTRS)
Dec 15 09:21:03 localhost kernel: [17181972.840000] SEQINTSRC[0x0] DFCNTRL[0x0]
DFSTATUS[0x89]:(FIFOEMP|HDONE|PRELOAD_AVAIL)
Dec 15 09:21:03 localhost kernel: [17181972.840000] SG_CACHE_SHADOW[0x2]:(LAST_SEG)
Dec 15 09:21:03 localhost kernel: [17181972.840000] SG_STATE[0x0]
DFFSXFRCTL[0x0] SOFFCNT[0x0]
Dec 15 09:21:03 localhost kernel: [17181972.840000]
MDFFSTAT[0...

[Ben Collins (ben-collins)]

*** Bug 27344 has been marked as a duplicate of this bug. ***

[Trouilliez vincent (vincent-trouilliez-modulonet)]

> > The kernel version is 2.6.15-7.9 (686 architecture) and the output of
>
> Attaching test module. To use these modules, perform this after downloading it:
>
> $ bunzip2 aic79xx.ko.bz2
> $ mv aic79xx.ko /lib/modules/2.6.15-7-686/kernel/drivers/scsi/aic7xxx/
> $ depmod -a
> $ update-initramfs -u -k 2.6.15-7-686
>
> Then reboot and see if the problem still occurs.

Could you roll me a aic7xxx module instead of aic 79xx ? I tried the aic79xx but
aic7xxx doesn't get loaded, despite I explicitely put it in /etc/module.

I use the current Dapper kernel: 2.6.15-8-386.

[Trouilliez vincent (vincent-trouilliez-modulonet)]

> I tried the aic79xx but aic7xxx doesn't get loaded, despite I explicitely put
it in /etc/module.

Sorry for the confusion. I of course mean that aic79xx doesn't load and that
aic7xxx keeps being loaded.

[Richard Kleeman (kleeman)]

Tried the 2.6.15-10 kernel as of 1/1/06 and the problem is still there. It can
be reproduced by inserting a standard
cd-rw disk (written) in the scsi cd-rw drive.

[Richard Kleeman (kleeman)]

Same problem still present with 2.6.15-11 kernel as of 5/1/06.

[Trouilliez vincent (vincent-trouilliez-modulonet)]

(In reply to comment #26)
> Same problem still present with 2.6.15-11 kernel as of 5/1/06.

Yep, I confirm... my old Plextor SCSI still isn't back to life yet...

[Richard Kleeman (kleeman)]

There seems to have been some progress on this issue in Fedora Core 4.
They are using a 2.6.14 kernel.
Details here: https://bugzilla.redhat.com/bugzilla/show_bug.cgi?id=146806

[Ben Collins (ben-collins)]

(In reply to comment #28)
> There seems to have been some progress on this issue in Fedora Core 4.
> They are using a 2.6.14 kernel.
> Details here: https://bugzilla.redhat.com/bugzilla/show_bug.cgi?id=146806

Looked through their source, but I can't find what in particular they used to
fix the problem.

[Richard Kleeman (kleeman)]

Tried again with kernel 2.6.15-12 and still fails. Interestingly however the kernel error messages have changed somewhat

( Protocol violation in Message-in phase. Attempting to abort.
[4296204.578000] (scsi0:A:4:0): Unexpected busfree in Message-in phase, 1 SCBs aborted, PRGMCNT == 0x198)

Full messages:

[4296204.362000] (scsi0:A:4:0): No or incomplete CDB sent to device.
[4296204.362000] scsi0: Issued Channel A Bus Reset. 1 SCBs aborted
[4296204.578000] (scsi0:A:4:0): No or incomplete CDB sent to device.
[4296204.578000] (scsi0:A:4:0): Protocol violation in Message-in phase. Attempt
ing to abort.
[4296204.578000] (scsi0:A:4:0): Unexpected busfree in Message-in phase, 1 SCBs a
borted, PRGMCNT == 0x198
[4296204.578000] >>>>>>>>>>>>>>>>>> Dump Card State Begins <<<<<<<<<<<<<<<<<
[4296204.578000] scsi0: Dumping Card State at program address 0x196 Mode 0x11
[4296204.578000] Card was paused
[4296204.578000] HS_MAILBOX[0x0] INTCTL[0x80]:(SWTMINTMASK)
[4296204.578000] SEQINTSTAT[0x0] SAVED_MODE[0x11]
[4296204.578000] DFFSTAT[0x13]:(CURRFIFO_NONE|FIFO0FREE)
[4296204.578000] SCSISIGI[0x0]:(P_DATAOUT) SCSIPHASE[0x0]
[4296204.578000] SCSIBUS[0x0] LASTPHASE[0xe0]:(P_MESGIN)
[4296204.578000] SCSISEQ0[0x0] SCSISEQ1[0x12]:(ENAUTOATNP|ENRSELI)
[4296204.578000] SEQCTL0[0x0] SEQINTCTL[0x0] SEQ_FLAGS[0x40]:(NO_CDB_SENT)
[4296204.578000] SEQ_FLAGS2[0x0] SSTAT0[0x0] SSTAT1[0x8]:(BUSFREE)
[4296204.578000] SSTAT2[0xc0]:(BUSFREE_DFF1) SSTAT3[0x0]
[4296204.578000] PERRDIAG[0xc0]:(HIPERR|HIZERO) SIMODE1[0xac]:(ENSCSIPERR|ENBUSF
REE|ENSCSIRST|ENSELTIMO)
[4296204.578000] LQISTAT0[0x0] LQISTAT1[0x0] LQISTAT2[0x0]
[4296204.578000] LQOSTAT0[0x0] LQOSTAT1[0x0] LQOSTAT2[0x0]
[richard@dual ~]$ more kernelmess
[4296204.362000] (scsi0:A:4:0): No or incomplete CDB sent to device.
[4296204.362000] scsi0: Issued Channel A Bus Reset. 1 SCBs aborted
[4296204.578000] (scsi0:A:4:0): No or incomplete CDB sent to device.
[4296204.578000] (scsi0:A:4:0): Protocol violation in Message-in phase. Attempting to abort.
[4296204.578000] (scsi0:A:4:0): Unexpected busfree in Message-in phase, 1 SCBs aborted, PRGMCNT == 0x198
[4296204.578000] >>>>>>>>>>>>>>>>>> Dump Card State Begins <<<<<<<<<<<<<<<<<
[4296204.578000] scsi0: Dumping Card State at program address 0x196 Mode 0x11
[4296204.578000] Card was paused
[4296204.578000] HS_MAILBOX[0x0] INTCTL[0x80]:(SWTMINTMASK)
[4296204.578000] SEQINTSTAT[0x0] SAVED_MODE[0x11]
[4296204.578000] DFFSTAT[0x13]:(CURRFIFO_NONE|FIFO0FREE)
[4296204.578000] SCSISIGI[0x0]:(P_DATAOUT) SCSIPHASE[0x0]
[4296204.578000] SCSIBUS[0x0] LASTPHASE[0xe0]:(P_MESGIN)
[4296204.578000] SCSISEQ0[0x0] SCSISEQ1[0x12]:(ENAUTOATNP|ENRSELI)
[4296204.578000] SEQCTL0[0x0] SEQINTCTL[0x0] SEQ_FLAGS[0x40]:(NO_CDB_SENT)
[4296204.578000] SEQ_FLAGS2[0x0] SSTAT0[0x0] SSTAT1[0x8]:(BUSFREE)
[4296204.578000] SSTAT2[0xc0]:(BUSFREE_DFF1) SSTAT3[0x0]
[4296204.578000] PERRDIAG[0xc0]:(HIPERR|HIZERO) SIMODE1[0xac]:(ENSCSIPERR|ENBUSFREE|ENSCSIRST|ENSELTIMO)
[4296204.578000] LQISTAT0[0x0] LQISTAT1[0x0] LQISTAT2[0x0]
[4296204.578000] LQOSTAT0[0x0] LQOSTAT1[0x0] LQOSTAT2[0x0]
[4296204.578000]
[4296204.578000] SCB Count = 4 CMDS_PENDING = 1 LASTSCB 0xffff CURRSCB 0x3 NEXTSCB 0x0
[4296204.578000] qinsta...

[Richard Kleeman (kleeman)]

As a sanity and hardware check I tried the the Knoppix live-cd which has kernel 2.6.12. k3b works perfectly in blanking and burning a cd-rw disk. Also no kernel error messages at all are produced. This seems a bit odd as the kernel they use does not seem heavily modified from Debian. If there are any other live distros of interest for testing purposes let me know.

[Richard Kleeman (kleeman)]

Same dmesg error output with the 2.6.15-13 kernel (1/20/06).

[Richard Kleeman (kleeman)]

Identical dmesg error output with 2.6.15-14 kernel (1/26/06)

[Ralph Corderoy (ralph-inputplus)]

Can people give feedback on my 2005-07-25 21:11:57 comment above.
I think I'm on the right track but don't have any time to investigate further.
Can others reproduce the successful results?

[Ben Collins (ben-collins)]

Have you tried reproducing that with a 2.6.15 kernel (boot to single user and user cdrecord directly)?

[Ralph Corderoy (ralph-inputplus)]

Sorry, still on Ubuntu 5.04 and the computer's been down for a couple of
months so I've a huge back-log of things to do. Perhaps Richard Kleeman
can try?

[Trouilliez vincent (vincent-trouilliez-modulonet)]

I just updated Dapper 10 minutes ago, still doesn't work. The CD writer (Plextor SCSI 12/10/32S) is detected properly, but that's about it... simply inserting a blank CD, makes the kernel throw errors, regardless of Gnome or not Gnome...

[Richard Kleeman (kleeman)]

Ben,
Do you think its worth me trying another kernel e.g. a vanilla kernel or maybe a 2.6.16 rc?

[Richard Kleeman (kleeman)]

OK I got impatient so I downloaded the vanilla 2.6.15.1 kernel and used the Ubuntu config file. Compiled it without problem and rebooted successfully. Here's the thing: Exactly the same problem occurs with identical kernel error messages. So the vanilla 2.6.15.1 doesn't work (without any patches) but the Knoppix kernel (2.6.12.4) works without issue. Wonder what is going on with the aic7.... kernel driver?

[Ralph Corderoy (ralph-inputplus)]

> but the Knoppix kernel (2.6.12.4)

Sorry to be a broken record, but Knoppix is KDE and not Gnome? When
people say "no Gnome was used in testing" do they mean it was in single
user mode with absolutely no Gnome processes running, or do they just
mean they did it from a text virtual console?

[Richard Kleeman (kleeman)]

OK so it looks like Ralph may be on the right track, at least for my hardware. Here's what I did:

switched inittab to boot at runlevel 1

inserted cdrw into drive. No kernel error messages produced.

Blanked the cdrw with cdrecord as follows:

cdrecord -blank=fast

This worked perfectly as far as I could see (the burn flashing light operated normally and the command ended normally and no kernel error messages were produced).

Next I switched the runlevel to 2 and executed /etc/init.d/gdm start
This is a gnome command but probably not important (?). I then logged into a kde session.

I then opened a terminal inserted a cdrw and executed

 cdrecord -blank=fast

Again no kernel error messages were produced and everything appeared to function normally.

I then tried a full iso burn with

cdrecord -dao -v -data *.iso

(* was some random iso file I had lying around).

No kernel error messages were produced and the burn appeared to work. I inserted the burnt cdrw into my other cd drive (an ide dvd/cd drive) and looked at it using konqueror. several kernel error messages were produced:

[4297863.278000] ide: failed opcode was: unknown
[4297863.278000] end_request: I/O error, dev hda, sector 1418944
[4297863.278000] Buffer I/O error on device hda, logical block 354736
[4297870.386000] hda: media error (bad sector): status=0x51 { DriveReady SeekComplete Error }
[4297870.386000] hda: media error (bad sector): error=0x30 { LastFailedSense=0x03 }
[4297870.386000] ide: failed opcode was: unknown
[4297870.386000] end_request: I/O error, dev hda, sector 1418948
[4297870.386000] Buffer I/O error on device hda, logical block 354737

One html file on the cd was difficult to read during these error messages.

A cdr version burnt on knoppix appeared fine however with no such error messages and the html file above was fine.

I then opened k3b and unfortunately it could not find my cd writer and kernel error messages like in previous posts here were produced.

Next I looged into gnome and retried the terminal command above. Now unlike a fresh gnome login they both (a blank and a burn) appeared to work. HOWEVER the following kernel error messages were produced:

[4297939.701000] scsi: unknown opcode 0xe9
[4297939.701000] scsi: unknown opcode 0xed
[4297940.533000] scsi: unknown opcode 0x01
[4298073.702000] scsi: unknown opcode 0xf5
[4299326.968000] scsi: unknown opcode 0xeb

The first three during the blanking and the last two during the burn.
Following the burn I placed the newly burnt cdrw into the other drive and now no kernel error messages were produced and the html file mentioned aboved opened fine. The cdrw did not mount automatically in gnome however this may be another issue.

OK this all looks rather mysterious to me. Any suggestions Ben or Ralph?

[Ralph Corderoy (ralph-inputplus)]

> OK so it looks like Ralph may be on the right track, at least for my
> hardware.

My theory when I was looking at it IIRC was that some Gnome process was
constantly on the look out for new media, e.g. USB memory stick or
CD-ROM. It saw the unwritten CD-R but ignored it. As cdrecord starts
to lay down intelligible data on the CD-R the next Gnome-process poll
spots it and tries to access it. This causes problems for cdrecord.

Whether Gnome's at fault for ignoring some advisory lock, or the kernel
driver should be giving it an EBUGGEROFF errno I don't know. I suspect
a little time working out the Gnome process involved and stracing it and
then kicking off a cdrecord may shed some more light.

[Richard Kleeman (kleeman)]

OK tried a few more experiments.

First off if I drop to runlevel 1 using
init 1

then no problems whatsoever occur. Mounting and writing of cd-rw works fine all the time (I tried many different isos and cd mounts).

I also tried a clean boot straight into kde and inserted a cd-rw into the drive. The same error messages as previously occurs and occasionally the kernel locks hard with a constant scroll of kernel scsi error messages. This suggests to me that the problem is lower level than gnome (unless gdm is enough to trigger the issue) since no gnome session was launched prior to all these errors.

I also removed all the nautilus burning packages and noticed no difference to the problem in gnome.

I also tried xfce with similar results.

I really need some guidance on this. Perhaps a developer who knows something about the scsi generic driver sg might help me out here.

I don't want to sound pushy but personally I wouldn't ignore this bug since kernel lockups are rather nasty and who knows how many people may be affected by this in the future if their particular hardware happens to trigger it.

[Ben Collins (ben-collins)]

On Sat, 2006-01-28 at 22:59 +0000, Richard Kleeman wrote:
> I really need some guidance on this. Perhaps a developer who knows something about the scsi generic driver sg might help me out here.
>
> I don't want to sound pushy but personally I wouldn't ignore this bug since kernel lockups are rather nasty and who knows how many people may be affected by this in the future if their particular hardware happens to trigger it.

Can you try unloading the sg_mod module? I don't think scsi generic is
really useful anymore (applications should just be able to access scd0
directly).

I'm guessing that Knoppix might work because either a) it isn't loading
sg_mod, or b) isn't starting whatever process is causing the clash.

--
Ben Collins
Kernel Developer - Ubuntu Linux

[Ralph Corderoy (ralph-inputplus)]

> I'm guessing that Knoppix might work because either a) it isn't
> loading sg_mod, or b) isn't starting whatever process is causing the
> clash.

Can we get input from Gnomers? If they point out the processes worth
watching then it can be debugged further by stracing to see what they're
doing.

[Richard Kleeman (kleeman)]

OK I think I may have made some progress on this.

As noted above If I insert the cdrw into the drive in gnome (or kde or xfce) it produces all the kernel error messages noted above. If I run from a 'init 1' terminal no error messages are produced.

Now in gnome if I issue

cdrecord -balnk=fast
cdrecord -dao -v -data dsl-2.1b.iso

everything WORKS FINE (as it does in the 'init 1') except that the following message is prduced by cdrecord in gnome but not the terminal:

Error trying to open /dev/cdrw exclusively (Device or resource busy)... retrying in 1 second

During the burn no kernel error messages are produced but as soon as the burn finishes (successfully) the kernel error messages resume and I can see the green lights flickering (this happens when a burnt cd-rw is inserted in anycase)

This all suggests to me strongly that it is gnome (or kde) trying (unsuccessfully) to mount or recognize in some fashion the media that is the source of the problem.

Mounting from an 'init 1' terminal works just fine by the way.

Finally the sg module being present makes no difference to the above. I rmmoded it and nothing changed.

I also rmmoded sr_mod and the kernel errors did not occur but then cdrecord could not find the drive.

[Richard Kleeman (kleeman)]

As a minor follow up clarification. The kernel error messages occur whether a burnt cd-rw or a regular cd-r are inserted into the drive. It makes no difference.

[Richard Kleeman (kleeman)]

More information:
I found that most kernel error messages can be eliminated by killing the
 hald-addon-storage processes (there are two). cdrecord then works without the additional error message noted above. Note that hal is not operating when a 'init 1' console is operational. I checked dmesg after killing these processes and some error messages are still produced in gnome however:

 [4297939.701000] scsi: unknown opcode 0xe9
[4297939.701000] scsi: unknown opcode 0xed
[4297940.533000] scsi: unknown opcode 0x01
[4298073.702000] scsi: unknown opcode 0xf5
[4299326.968000] scsi: unknown opcode 0xeb

In addition if I try to access the written cd-rw using nautilus I get a hard kernel lockup.

[Ralph Corderoy (ralph-inputplus)]

> I found that most kernel error messages can be eliminated by killing
> the hald-addon-storage processes (there are two).

My older Ubuntu system, 5.04, doesn't have hald-addon-storage processes.

    $ ps xaww | g hald
     6872 ? Ss 0:01 /usr/sbin/hald --drop-privileges
    29664 pts/1 S+ 0:00 grep -E hald
    $

If I strace hald it's polling several file descriptors and regularly opening
/dev/scd0 to ioctl(CDROM_DRIVE_STATUS) it.

    $ sudo strace -p 6872
    Process 6872 attached - interrupt to quit
    gettimeofday({1138625597, 428745}, NULL) = 0
    gettimeofday({1138625597, 428978}, NULL) = 0
    poll([{fd=6, events=POLLIN}, {fd=10, events=POLLIN}, {fd=8, events=POLLIN}, {fd=9, events=POLLIN}, {fd=14, events=POLLIN|POLLPRI}], 5, 849) = 0
    gettimeofday({1138625598, 279090}, NULL) = 0
    open("/dev/scd0", O_RDONLY|O_NONBLOCK|O_EXCL|O_LARGEFILE) = 3
    ioctl(3, CDROM_DRIVE_STATUS, 0x7fffffff) = 2
    close(3) = 0
    time(NULL) = 1138625598
    gettimeofday({1138625598, 306502}, NULL) = 0
    poll(...

    $ sudo strace -ttt -p 6872 2>&1 | g /dev/scd0
    1138625702.325428 open("/dev/scd0", O_RDONLY|O_NONBLOCK|O_EXCL|O_LARGEFILE) = 3
    1138625704.327099 open("/dev/scd0", O_RDONLY|O_NONBLOCK|O_EXCL|O_LARGEFILE) = 3
    1138625706.327802 open("/dev/scd0", O_RDONLY|O_NONBLOCK|O_EXCL|O_LARGEFILE) = 3
    1138625708.328481 open("/dev/scd0", O_RDONLY|O_NONBLOCK|O_EXCL|O_LARGEFILE) = 3

Perhaps you can monitor hald-addon-storage to see what it does when
recording is interrupted.

Alternatively, use lshal (search output for /dev/scd0) and
hal-[gs]et-property to tinker with some of the options and see if one of
them turns off the mucking around with /dev/scd0 during record, e.g.
auto-mount.

    $ hal-get-property --udi /org/freedesktop/Hal/devices/scsi_0_0_4_0 \
    > --key scsi.target
    4

[Richard Kleeman (kleeman)]

Ralph,
Thanks for your suggestions. I straced the two hald-addon-storage and it appears one of them is polling my ide dvd drive and the other the scsi cdburner (logical!). Here is the output from the second one before and after I insert a cdrw (and the dmesg kernel error messages start). Note that if I do a cdrecord these kernel messages end I think because cdrecord is given a lock on the device.

 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigaction(SIGCHLD, NULL, {SIG_DFL}, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
nanosleep({2, 0}, {2, 0}) = 0
open("/dev/scd0", O_RDONLY|O_NONBLOCK|O_EXCL|O_LARGEFILE) = 4
ioctl(4, CDROM_DRIVE_STATUS, 0x7fffffff) = 2
close(4) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigaction(SIGCHLD, NULL, {SIG_DFL}, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
nanosleep({2, 0}, {2, 0}) = 0
open("/dev/scd0", O_RDONLY|O_NONBLOCK|O_EXCL|O_LARGEFILE) = 4
ioctl(4, CDROM_DRIVE_STATUS, 0x7fffffff) = 2
close(4) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigaction(SIGCHLD, NULL, {SIG_DFL}, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
nanosleep({2, 0}, {2, 0}) = 0
open("/dev/scd0", O_RDONLY|O_NONBLOCK|O_EXCL|O_LARGEFILE) = 4
ioctl(4, CDROM_DRIVE_STATUS, 0x7fffffff) = 2
close(4) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigaction(SIGCHLD, NULL, {SIG_DFL}, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
nanosleep({2, 0}, {2, 0}) = 0
open("/dev/scd0", O_RDONLY|O_NONBLOCK|O_EXCL|O_LARGEFILE) = 4
ioctl(4, CDROM_DRIVE_STATUS, 0x7fffffff) = 4
ioctl(4, CDROM_MEDIA_CHANGED, 0x7fffffff) = 1
ioctl(4, CDROM_MEDIA_CHANGED, 0x7fffffff) = 0
ioctl(4, CDROM_SEND_PACKET, 0xbfa343fc) = 0
close(4) = 0
writev(3, [{"l\1\0\1\0\0\0\0\5\0\0\0\237\0\0\0\1\1o\0;\0\0\0/org/fr"..., 176}, {"", 0}], 2) = 176
gettimeofday({1138630782, 590620}, NULL) = 0
poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 25000) = 1
read(3, "l\2\1\1\4\0\0\0\5\0\0\0\17\0\0\0\5\1u\0\5\0\0\0\10\1g\0"..., 2048) = 36read(3, 0x804e1c8, 2048) = -1 EAGAIN (Resource temporarily unavailable)
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigaction(SIGCHLD, NULL, {SIG_DFL}, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
nanosleep({2, 0}, {2, 0}) = 0
open("/dev/scd0", O_RDONLY|O_NONBLOCK|O_EXCL|O_LARGEFILE) = 4
ioctl(4, CDROM_DRIVE_STATUS, 0x7fffffff) = 4
ioctl(4, CDROM_MEDIA_CHANGED, 0x7fffffff) = 1
ioctl(4, CDROM_MEDIA_CHANGED, 0x7fffffff) = 0
ioctl(4, CDROM_SEND_PACKET, 0xbfa343fc) = 0
close(4) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigaction(SIGCHLD, NULL, {SIG_DFL}, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
nanosleep({2, 0}, {2, 0}) = 0
open("/dev/scd0", O_RDONLY|O_NONBLOCK|O_EXCL|O_LARGEFILE) = 4
ioctl(4, CDROM_DRIVE_STATUS, 0x7fffffff) = 4
ioctl(4, CDROM_MEDIA_CHANGED, 0x7fffffff) = 1
ioctl(4, CDROM_MEDIA_CHANGED, 0x7fffffff) = 0
ioctl(4, CDROM_SEND_PACKET, 0xbfa343fc) = 0
close(4) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], ...

[Richard Kleeman (kleeman)]

The dvd drive output above was with a blanked cdrw which did not mount. If it is written it does mount and the strace output is:

open("/dev/hda", O_RDONLY|O_NONBLOCK|O_EXCL|O_LARGEFILE) = 4
ioctl(4, CDROM_DRIVE_STATUS, 0x7fffffff) = 4
ioctl(4, CDROM_MEDIA_CHANGED, 0x7fffffff) = 1
ioctl(4, CDROM_MEDIA_CHANGED, 0x7fffffff) = 0
ioctl(4, CDROM_SEND_PACKET, 0xbfafcc3c) = 0
close(4) = 0
writev(3, [{"l\1\0\1\0\0\0\0\17\0\0\0\247\0\0\0\1\1o\0@\0\0\0/org/f"..., 184}, {"", 0}], 2) = 184
gettimeofday({1138632600, 293913}, NULL) = 0
poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 25000) = 1
read(3, "l\2\1\1\4\0\0\0\17\0\0\0\17\0\0\0\5\1u\0\17\0\0\0\10\1"..., 2048) = 36
read(3, 0x804e1c8, 2048) = -1 EAGAIN (Resource temporarily unavailable)
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigaction(SIGCHLD, NULL, {SIG_DFL}, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
nanosleep({2, 0}, {2, 0}) = 0
open("/dev/hda", O_RDONLY|O_NONBLOCK|O_EXCL|O_LARGEFILE) = -1 EBUSY (Device or resource busy)
open("/etc/mtab", O_RDONLY) = 4
fstat64(4, {st_mode=S_IFREG|0644, st_size=613, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fe4000
read(4, "/dev/sda11 / ext3 rw,errors=remo"..., 4096) = 613
close(4) = 0
munmap(0xb7fe4000, 4096) = 0
open("/dev/hda", O_RDONLY|O_NONBLOCK|O_LARGEFILE) = 4
ioctl(4, CDROM_DRIVE_STATUS, 0x7fffffff) = 4
ioctl(4, CDROM_MEDIA_CHANGED, 0x7fffffff) = 0
ioctl(4, CDROM_SEND_PACKET, 0xbfafcc3c) = 0
close(4) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigaction(SIGCHLD, NULL, {SIG_DFL}, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
nanosleep({2, 0}, {2, 0}) = 0
open("/dev/hda", O_RDONLY|O_NONBLOCK|O_EXCL|O_LARGEFILE) = -1 EBUSY (Device or resource busy)
open("/etc/mtab", O_RDONLY) = 4
fstat64(4, {st_mode=S_IFREG|0644, st_size=613, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fe4000
read(4, "/dev/sda11 / ext3 rw,errors=remo"..., 4096) = 613
close(4) = 0
munmap(0xb7fe4000, 4096) = 0
open("/dev/hda", O_RDONLY|O_NONBLOCK|O_LARGEFILE) = 4
ioctl(4, CDROM_DRIVE_STATUS, 0x7fffffff) = 4
ioctl(4, CDROM_MEDIA_CHANGED, 0x7fffffff) = 0
ioctl(4, CDROM_SEND_PACKET, 0xbfafcc3c) = 0
close(4) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigaction(SIGCHLD, NULL, {SIG_DFL}, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
nanosleep({2, 0}, {2, 0}) = 0
open("/dev/hda", O_RDONLY|O_NONBLOCK|O_EXCL|O_LARGEFILE) = -1 EBUSY (Device or resource busy)
open("/etc/mtab", O_RDONLY) = 4
fstat64(4, {st_mode=S_IFREG|0644, st_size=613, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fe4000
read(4, "/dev/sda11 / ext3 rw,errors=remo"..., 4096) = 613
close(4) = 0
munmap(0xb7fe4000, 4096) = 0
open("/dev/hda", O_RDONLY|O_NONBLOCK|O_LARGEFILE) = 4
ioctl(4, CDROM_DRIVE_STATUS, 0x7fffffff) = 4
ioctl(4, CDROM_MEDIA_C...

[Richard Kleeman (kleeman)]

I did an strace on the gnome-volume-manager and it shows nothing at all i.e. does not respond to the insertion of the cd-rw. This strongly suggests the problem is with hal and its communication with the hardware. The problem seems a bit like this resolved scsi hal issue (which was marked as critical):

https://bugs.freedesktop.org/show_bug.cgi?id=1852

Ben,

Do you think I should lodge a bug report on the hal bugzilla and mark this as upstream? Or do you think we should dig further into hal to find out exactly what the call is that causes the kernel problems...

[Ben Collins (ben-collins)]

On Thu, 2006-02-02 at 23:15 +0000, Richard Kleeman wrote:
> Ben,
>
> Do you think I should lodge a bug report on the hal bugzilla and mark
> this as upstream? Or do you think we should dig further into hal to find
> out exactly what the call is that causes the kernel problems...

It's possible hal is reacting to a bug in the kernel. One possibility is
that it is getting incorrect information about the state of the drive
during key points where you are seeing errors.

I don't know enough about hal to suggest how to find the problem though.

--
Ben Collins
Kernel Developer - Ubuntu Linux

[Ralph Corderoy (ralph-inputplus)]

> It's possible hal is reacting to a bug in the kernel. One possibility
> is that it is getting incorrect information about the state of the
> drive during key points where you are seeing errors.
>
> I don't know enough about hal to suggest how to find the problem
> though.

I suspect it's a kernel problem, but one that's easier to debug from the
user-space side, i.e. knowing what system calls are made, when, and why.
I suggest the bug's re-assigned to Gnome, hal, or cdrecord for their
input. They'll probably know fairly quickly what's being attempted and
will know where they think the fault lies.

Cheers,

Ralph.

[Richard Kleeman (kleeman)]

I would support having a hal expert look at this. If I could fire a few low level hal drectives at the kernel we might (under supervision ;-)) get somewhere on tracking this down to either a kernel module problem or a hal device registration issue.

Cheers,
Richard

[Richard Kleeman (kleeman)]

OK a new version of hal came in today (2/14) and the problem just got decidedly worse. If I insert a cd-rw in the drive it sits there for some time without kernel error and then the following series of very nasty messages are produced (taken from /var/log/messages). The last 20 lines or so repeats endlessly and only a hard power reset can rescue the system. I also performed a hal log analysis as suggested here by Martin Pitt:

https://wiki.ubuntu.com/DebuggingRemovableDevices?highlight=%28debug%29

I have attached two hal logs. One from breezy where the cd-rw is automounted fine and one from dapper where the problems occur. They are very different. Should Martin be cc'd on this bug?

Feb 14 13:38:01 localhost kernel: [4294982.727000] sr 0:0:4:0: Attempting to queue an ABORT message:CDB: 0x28 0x0 0x0 0x0 0x0 0x12 0x0 0x0 0x2 0x0
Feb 14 13:38:01 localhost kernel: [4294982.727000] scsi0: At time of recovery, card was not paused
Feb 14 13:38:01 localhost kernel: [4294982.727000] >>>>>>>>>>>>>>>>>> Dump Card State Begins <<<<<<<<<<<<<<<<<
Feb 14 13:38:01 localhost kernel: [4294982.727000] scsi0: Dumping Card State at program address 0x198 Mode 0x11
Feb 14 13:38:01 localhost kernel: [4294982.727000] Card was paused
Feb 14 13:38:01 localhost kernel: [4294982.727000] HS_MAILBOX[0x0] INTCTL[0x80]:(SWTMINTMASK)
Feb 14 13:38:01 localhost kernel: [4294982.727000] SEQINTSTAT[0x0] SAVED_MODE[0x11]
Feb 14 13:38:01 localhost kernel: [4294982.727000] DFFSTAT[0x19]:(CURRFIFO_1|FIFO0FREE)
Feb 14 13:38:01 localhost kernel: [4294982.727000] SCSISIGI[0x84]:(P_COMMAND|BSYI) SCSIPHASE[0x0]
Feb 14 13:38:01 localhost kernel: [4294982.727000] SCSIBUS[0x0] LASTPHASE[0x80]:(P_COMMAND)
Feb 14 13:38:01 localhost kernel: [4294982.727000] SCSISEQ0[0x0] SCSISEQ1[0x12]:(ENAUTOATNP|ENRSELI)
Feb 14 13:38:01 localhost kernel: [4294982.727000] SEQCTL0[0x0] SEQINTCTL[0x0] SEQ_FLAGS[0x0]
Feb 14 13:38:01 localhost kernel: [4294982.727000] SEQ_FLAGS2[0x0] SSTAT0[0x0] SSTAT1[0x8]:(BUSFREE)
Feb 14 13:38:01 localhost kernel: [4294982.727000] SSTAT2[0x0] SSTAT3[0x0] PERRDIAG[0xc0]:(HIPERR|HIZERO)
Feb 14 13:38:01 localhost kernel: [4294982.727000] SIMODE1[0xac]:(ENSCSIPERR|ENBUSFREE|ENSCSIRST|ENSELTIMO)
Feb 14 13:38:01 localhost kernel: [4294982.727000] LQISTAT0[0x0] LQISTAT1[0x0] LQISTAT2[0x0]
Feb 14 13:38:01 localhost kernel: [4294982.727000] LQOSTAT0[0x0] LQOSTAT1[0x0] LQOSTAT2[0x0]
Feb 14 13:38:01 localhost kernel: [4294982.727000]
Feb 14 13:38:01 localhost kernel: [4294982.727000] SCB Count = 4 CMDS_PENDING = 2 LASTSCB 0xffff CURRSCB 0x2 NEXTSCB 0x0
Feb 14 13:38:01 localhost kernel: [4294982.727000] qinstart = 8519 qinfifonext = 8519
Feb 14 13:38:01 localhost kernel: [4294982.727000] QINFIFO:
Feb 14 13:38:01 localhost kernel: [4294982.727000] WAITING_TID_QUEUES:
Feb 14 13:38:01 localhost kernel: [4294982.727000] Pending list:
Feb 14 13:38:01 localhost kernel: [4294982.727000] 2 FIFO_USE[0x0] SCB_CONTROL[0x40]:(DISCENB)
Feb 14 13:38:01 localhost kernel: [4294982.727000] SCB_SCSIID[0x47]
Feb 14 13:38:01 localhost kernel: [4294982.727000] 3 FIFO_USE[0x0] SCB_CONTROL[0x44]:(DISCONNECTED|DISCENB)
Feb 14 13:38:01 localhost kernel: [4294982.727000] SCB_SCSIID[0x47]
Feb 14 13:38:01 local...

[Richard Kleeman (kleeman)]

hal breezy log

[Richard Kleeman (kleeman)]

hal dapper log

[Richard Kleeman (kleeman)]

Ben,

There is a rather large git patch update by James Bottomley which updates the aic79xx driver in the kernel from version 1.3.11 (the present dapper version) up to Version 3.0. According to this link:

http://lwn.net/Articles/167711/

the changes are rather substantial and include many bugfixes. Would it be possible for this to be included in Dapper? If not could you give me some instructions for applying this patch so I can test whether it solves the problems above?

The changes are rather large and there doesn't appear to have been a substantial revision to aic79xx for quite a long time so it looks like it could be worth a shot....

[Richard Kleeman (kleeman)]

Some further information:

I patched a vanilla 2.6.15 kernel with the git12 patch which contains the aic79xx (and aic7xxx) upgrade. I did this in both dapper and breezy.

In both cases version 3.0 of aic79xx loads and the system boots to a gnome desktop. The seagate scsi hard disks appear to function normally with the updated driver.

I then loaded a (written) cd-rw in the burner and in both cases (dapper and breezy) after approximately a minute (during which the burner appears to try to mount the cd-rw) I experienced a hard kernel lockup. A manual power reset was required in both cases.

When the same action is performed with the 2.6.12 kernel in breezy the cd-rw is mounted normally and nautilus displays its contents. So it appears that it is the kernel upgrade not the hal upgrade which is the source of the problem. In addition upgrading the aic79xx driver does not help.

[Richard Kleeman (kleeman)]

I checked the linux-scsi mailing list and there is a lot of recent patching activity going on regarding both the aic79xx and aic7xxx drivers. This is driven by similar lockups with cd-rw as the ones reported here.

So it appears that patience is called for and I will be unable to upgrade from breezy to dapper. Bummer!

[Trouilliez vincent (vincent-trouilliez-modulonet)]

I am overjoyed to report that things have much, MUCH improved in the last few days. The drive used to be 200% useless (detected by the kernel at boot.... and that was about it ! ), but now if I insert a blank CD in the drive, Nautilus detects it instantly, and I can successfully burn an ISO (I tried with Flight 4 ISO) at full speed without a glith, with no kernel messages other than those :

Feb 22 03:51:34 Lotus-Esprit kernel: [4296634.108000] cdrom: This disc doesn't have any tracks I recognize!
Feb 22 03:51:50 Lotus-Esprit kernel: [4296649.993000] cdrom: This disc doesn't have any tracks I recognize!
Feb 22 03:51:50 Lotus-Esprit kernel: [4296650.003000] cdrom: This disc doesn't have any tracks I recognize!
Feb 22 03:51:50 Lotus-Esprit kernel: [4296650.028000] cdrom: This disc doesn't have any tracks I recognize!

I also tried burning an audio CD using Rhythmbox, and that worked too, although not quite glitch free : many kernel messages were printed, I got an error window (with no really informative content AFAIR) at the end of the burning process, and the CD drive was unable to mount the CD. However if I put the CD in a different drive (my DVD drive for instance), Nautilus detects it properly as an audio CD, and RB can play it perfectly.

Also, as a bonus, the drive can now READ CD's just fine. In Breezy, it would write but not read.

So as far as I am concerned, it now works, and even better than in Breezy... I just hope it won't break again by the time Dapper gets released ! ;-P

[Trouilliez vincent (vincent-trouilliez-modulonet)]

"Also, as a bonus, the drive can now READ CD's just fine. "

Apart from the audio CD burned with RB, of course, ie.

[Ben Collins (ben-collins)]

I'm backporting the aix7xxx drivers from 2.6.16-git, since they seem to have a lot of updates there. It will be uploaded with the 2.6.15-17.25 upload.

Please test, and confirm whether it works or not. Upload will happen within the next week.

[Richard Kleeman (kleeman)]

Thanks Ben I'll check it out. Seems like there is a lot of chat going on over this driver on the kernel scsi list.

Here's an amusing quote from Linus Torvalds which _might_ have relevance:

"Not that I expect people to have a SCSI CD/DVD drive anyway in this day
and age, so the sg.c changes probably won't show up at all."

and a classic Torvald's quote from the same thread:

"I have a saying: "On the internet, nobody can hear you being subtle".

So I don't much do "polite". Sorry."

[Trouilliez vincent (vincent-trouilliez-modulonet)]

Ahhh. Well, if Linus doesn't mind giving me 100 Euros so I can buy a brand new IDE Plextor DVD writer, and 400 Euros for a decent scanner, then why not. But since that's not going to happen, please Mister Linus allow me to use my SCSI scanner and CD burner, thanks much in advance....

[Richard Kleeman (kleeman)]

LOL Vincent!

[Richard Kleeman (kleeman)]

Ben,

I tried the latest kernel with the 2.6.16 git backport of the new aic79xx driver and things have got much worse unfortunately.

A kernel lockup on boot now occurs.

I switched the boot options to non-quiet and watched the messages as the boot proceeded. It got some considerable way through. I could see the two scsi devices being loaded and noted that the 3.0 version of aic79xx was doing the honours. The kernel locked up after a series of scsi errors quite similar to those noted in previous comments above. In particular the last line before lockup was:

>>>>>>>>>>>>>>>>>> Dump Card State Begins>>>>>>>>>>>

I would worry a lot that this change may be very buggy and affect not just us rare beings with a scsi cd burner.

[Trouilliez vincent (vincent-trouilliez-modulonet)]

I confirm that the latest kernel updates ( 17 & 18) broke it again.

When I burn a data CD, it starts writing to the CD, but after a minute or so, the progress bar (Nautilus CD burner) stops (no error message or anything, it just stops). No kernel message to be seen, until I ask Nautilus to cancel the writing, and then I get that dreaded " >>>>>>>> Dump Card State Begins>>>>" stuff.
I tried twice, and the second time, although it stopped again, I tried reading that supposedly "half-backed" CD, and to my surprise, Nautilus could read it back just fine, and all the data were present ! Strange. So maybe writing the data does work, and it only stops when it's about to "fixate" the CD ?

Other strange thing I noticed is that whenever I ask Nautilus to eject a CD be it a blank CD or a data CD), it pops up a weird dialog aong the lines of "Storing infirmation about the CD-RW CD, please wait and don't eject the CD until that's done". I can't make any sense of this dialog :-/
All I know is that closing the dialog and ejecting the Cd by hand, doesn't seem to have any ill effects. Really strange and unexpected dialog indeed...

[Richard Kleeman (kleeman)]

Two things to report:

1) kernel update 19 still refuses to boot with a scsi kernel dump error message.

2) I compiled the just released vanilla 2.6.16 kernel on breezy (with CC=gcc3.4). This has the 3.0 version of aic79xx in it. The kernel boots fine (in breezy) WITHOUT ERROR and moreover cd-burning appears to be FUNCTIONING FINE except for the following kernel messages:

[17180127.364000] scsi: unknown opcode 0xe9
[17180127.364000] scsi: unknown opcode 0xed
[17180128.208000] scsi: unknown opcode 0x01
[17180312.152000] scsi: unknown opcode 0xf5
[17181369.648000] scsi: unknown opcode 0xeb

which are also seen on a standard breezy boot with kernel 2.6.12-10-686-smp

Ben, does this suggests that the aic79xx driver is not the fundamental problem here?

This whole thing is very confusing...

[Richard Kleeman (kleeman)]

Further report:

I installed the vanilla 2.6.16 kernel on dapper as opposed to breezy (previous report). This kernel fails to boot in an identical fashion to the 2.6.15-17/18/19 standard dapper kernels.

So the latest kernel 2.6.16 with the latest aic79xx scsi driver works fine on breezy and fails to boot completely on dapper.

Are there any simple tests I could run on dapper to find out exactly what in userspace is triggering this problem?

[Richard Kleeman (kleeman)]

Reinstalled dapper from a fresh breezy install using apt-get dist-upgrade. The latest kernel (2.6.15-19) with version 3.0 of aic79xx now boots however during the boot the same error message as previously occurs. I have listed it:

[4294705.439000] SCSI device sda: 286749488 512-byte hdwr sectors (146816 MB)
[4294705.954000] scsi1: Invalid Sequencer interrupt occurred.
[4294705.954000] >>>>>>>>>>>>>>>>>> Dump Card State Begins <<<<<<<<<<<<<<<<<
[4294705.954000] scsi1: Dumping Card State at program address 0x236 Mode 0x0
[4294705.954000] Card was paused
[4294705.954000] INTSTAT[0x0] SELOID[0x4] SELID[0x0]
[4294705.954000] HS_MAILBOX[0x0] INTCTL[0x80]:(SWTMINTMASK)
[4294705.954000] SEQINTSTAT[0x0] SAVED_MODE[0x11]
[4294705.954000] DFFSTAT[0x33]:(CURRFIFO_NONE|FIFO0FREE|FIFO1FREE)
[4294705.954000] SCSISIGI[0x0]:(P_DATAOUT) SCSIPHASE[0x0]
[4294705.954000] SCSIBUS[0x0] LASTPHASE[0x1]:(P_DATAOUT|P_BUSFREE)
[4294705.954000] SCSISEQ0[0x0] SCSISEQ1[0x12]:(ENAUTOATNP|ENRSELI)
[4294705.954000] SEQCTL0[0x0] SEQINTCTL[0x6]:(INTMASK1|INTMASK2)
[4294705.954000] SEQ_FLAGS[0x0] SEQ_FLAGS2[0x0] QFREEZE_COUNT[0x1]
[4294705.954000] KERNEL_QFREEZE_COUNT[0x1] MK_MESSAGE_SCB[0xff00]
[4294705.954000] MK_MESSAGE_SCSIID[0xff] SSTAT0[0x0]
[4294705.954000] SSTAT1[0x0] SSTAT2[0x0] SSTAT3[0x0]
[4294705.954000] PERRDIAG[0x0] SIMODE1[0xa4]:(ENSCSIPERR|ENSCSIRST|ENSELTIMO)
[4294705.954000] LQISTAT0[0x0] LQISTAT1[0x0] LQISTAT2[0x0]
[4294705.954000] LQOSTAT0[0x0] LQOSTAT1[0x0] LQOSTAT2[0xe1]:(LQOSTOP0|LQOPKT)
[4294705.954000]
[4294705.954000] SCB Count = 4 CMDS_PENDING = 0 LASTSCB 0xffff CURRSCB 0x3 NEXTSCB 0xff80
[4294705.954000] qinstart = 30 qinfifonext = 30
[4294705.954000] QINFIFO:
[4294705.954000] WAITING_TID_QUEUES:
[4294705.954000] Pending list:
[4294705.954000] Total 0
[4294705.954000] Kernel Free SCB list: 2 3 1 0
[4294705.954000] Sequencer Complete DMA-inprog list:
[4294705.954000] Sequencer Complete list:
[4294705.954000] Sequencer DMA-Up and Complete list:
[4294705.954000] Sequencer On QFreeze and Complete list:
[4294705.954000]
[4294705.954000]
[4294705.954000] scsi1: FIFO0 Free, LONGJMP == 0x8000, SCB 0x2
[4294705.954000] SEQIMODE[0x3f]:(ENCFG4TCMD|ENCFG4ICMD|ENCFG4TSTAT|ENCFG4ISTAT|ENCFG4DATA|ENSAVEPTRS)
[4294705.954000] SEQINTSRC[0x0] DFCNTRL[0x0] DFSTATUS[0x89]:(FIFOEMP|HDONE|PRELOAD_AVAIL)
[4294705.954000] SG_CACHE_SHADOW[0x2]:(LAST_SEG) SG_STATE[0x0]
[4294705.954000] DFFSXFRCTL[0x0] SOFFCNT[0x0] MDFFSTAT[0x5]:(FIFOFREE|DLZERO)
[4294705.954000] SHADDR = 0x00, SHCNT = 0x0 HADDR = 0x00, HCNT = 0x0
[4294705.954000] CCSGCTL[0x10]:(SG_CACHE_AVAIL)
[4294705.954000]
[4294705.954000] scsi1: FIFO1 Free, LONGJMP == 0x8063, SCB 0x3
[4294705.954000] SEQIMODE[0x3f]:(ENCFG4TCMD|ENCFG4ICMD|ENCFG4TSTAT|ENCFG4ISTAT|ENCFG4DATA|ENSAVEPTRS)
[4294705.954000] SEQINTSRC[0x0] DFCNTRL[0x0] DFSTATUS[0x89]:(FIFOEMP|HDONE|PRELOAD_AVAIL)
[4294705.954000] SG_CACHE_SHADOW[0x2]:(LAST_SEG) SG_STATE[0x0]
[4294705.954000] DFFSXFRCTL[0x0] SOFFCNT[0x0] MDFFSTAT[0x5]:(FIFOFREE|DLZERO)
[4294705.954000] SHADDR = 0x00, SHCNT = 0x0 HADDR = 0x00, HCNT = 0x0
[4294705.954000] CCSGCTL[0x10]:(SG_CACHE_AVAIL)
[4294705.954000] LQIN: 0x8 0x0 0x0 0x2 0x0 0x0 ...

[Richard Kleeman (kleeman)]

I checked the 2.6.17-rc1 changes just released by Linus and I note the following:

Hannes Reinecke:
      [SCSI] aic79xx: remove qfrozen
      [SCSI] aic79xx: use tcq functions
      [SCSI] aic79xx: Remove dead code
      [SCSI] aic79xx: Update error recovery
      [SCSI] aic79xx: Invalid Sequencer interrupt occured
      [SCSI] aic79xx: use BIOS settings
      [SCSI] aic79xx: Avoid renegotiation on inquiry

Note that "qfrozen" and "Invalid Sequencer interrupt occured" are in the error messages I have listed above.

I will try this kernel and see what happens.

[Richard Kleeman (kleeman)]

EXCELLENT NEWS!

The 2.6.17-rc1 kernel makes this bug virtually disappear.

cd-r disks mount as expected
cd-rw disks can be written to successfully using nautilus.
None of the previous nasty kernel error messages occur.

The remaining wrinkle is that the following messages occur in dmesg during a burn:
[4319535.861000] scsi: unknown opcode 0xe9
[4319535.861000] scsi: unknown opcode 0xed
[4319538.762000] scsi: unknown opcode 0x01

and two others. However there appear no bad side effects and I noted that similar messages occured with the breezy kernel.

So I would say this bug might be able to be closed if the aic79xx changes noted above could be backported to dapper.

Ben is that possible??? PLEASE!

Note: I do not know whether aic7xxx is fixed in rc1 however.....

[Richard Kleeman (kleeman)]

Ben,

I tried the new 2.6.15-21 kernel which has the aic79xx driver from 2.6.17-rc synched and there are big problems:

When booted a large number of aic79xx kernel error messages appear. They fly rapidly accross the screen however they all seem to mention a

                        "spipopulate"

error

The system then hangs waiting for a root file system suggesting that the hard drive (also handled by aic79xx as it is a seagate scsi drive) is not being seen because of the above kernel errors.

I have tried the 2.6.17-rc2 kernel as well and it works as well as the rc1 version although I do notice somewhat more kernel warning messages. These do not appear to affect functionality however.

[Richard Kleeman (kleeman)]

With the 22.34 version of the kernel performance is the same as the 2.6.17-rc kernel. If Vincent can confirm with the aic7xxx driver I would suggest this bug might be able to be closed.

[Trouilliez vincent (vincent-trouilliez-modulonet)]

> If Vincent can confirm with the aic7xxx driver I would suggest
> this bug might be able to be closed.

I just had the opportunity to use my CD writer today (to burn Flight7). At first, with my SCSI scanner powered off (as it is always by default, to save power), the CD writer was detected, but later in the boot process, I got the dreaded "Dumping card State" stuff, and it hung there (not hard locked though, I could reboot using the keyboard)
Then I powered up the scanner, rebooted, and somehow all was well: CD writer was detected properly, no error messages during the boot sequence, and no problem at all when burning the ISO wih Nautilus.

I don't quite see why the scanner, obviously external, would interfere with the CD writer which is internal (I thought the internal and external buses were electronically distinct), but I am sick of recurrent problems with this SCSI driver over each and every distro release, so if all I have to do to get the writer to work, is to think of powering up the scanner, then I will be more happy to vote in favour of closing this bug...

[Ralph Corderoy (ralph-inputplus)]

I've just found that the aic7xxx kernel module is a re-write and the old version is still present as aic7xxx_old.

$ cd /lib/modules/`uname -r` && find -name 'aic7xxx*.ko'
./kernel/drivers/scsi/aic7xxx_old.ko
./kernel/drivers/scsi/aic7xxx/aic7xxx.ko
$

How can I configure my Ubuntu installation to use aic7xxx_old in preference to aic7xxx on booting? If I can do this, I can then see if all the problems disappear and workaround the issue for the time being.