dc395x: CD writer causes endless "sg_to_virt failed" loop

I have a Tekram DC395UW card, running in Debian with kernel 2.6.3 and the dc395x driver from the kernel source. Attached to the card are a Seagate Travan NS20 tape drive, and an HP 9200i CD writer:

Mar 27 09:50:53 helium kernel: dc395x: Tekram DC395(U/UW/F), DC315(U) - ASIC TRM-S1040 v2.04, 2003/05/19
Mar 27 09:50:53 helium kernel: dc395x: Used settings: AdapterID=07, Speed=0(20.0MHz), dev_mode=0x77
Mar 27 09:50:53 helium kernel: dc395x:                AdaptMode=0x0f, Tags=4(16), DelayReset=1s
Mar 27 09:50:53 helium kernel: dc395x: (Wide) Connectors: int50  Termination: Auto Low High
Mar 27 09:50:53 helium kernel: dc395x: Performing initial SCSI bus reset
Mar 27 09:50:53 helium kernel: scsi2 : Tekram DC395(U/UW/F), DC315(U) - ASIC TRM-S1040 v2.04, 2003/05/19
Mar 27 09:50:55 helium kernel: dc395x: Target 02:  Sync: 100ns Offset 15 (10.0 MB/s)
Mar 27 09:50:55 helium kernel:   Vendor: Seagate   Model: STT20000N         Rev: 7A61
Mar 27 09:50:55 helium kernel:   Type:   Sequential-Access                  ANSI SCSI revision: 02
Mar 27 09:50:55 helium scsi.agent[2072]: tape at /devices/pci0000:00/0000:00:1e.0/0000:02:04.0/host2/2:0:2:0
Mar 27 09:50:55 helium kernel: st: Version 20040122, fixed bufsize 32768, s/g segs 256
Mar 27 09:50:55 helium kernel: Attached scsi tape st0 at scsi2, channel 0, id 2, lun 0
Mar 27 09:50:55 helium kernel: st0: try direct i/o: yes, max page reachable by HBA 1048575
Mar 27 09:50:56 helium kernel: dc395x: Target 06:  Sync: 100ns Offset 15 (10.0 MB/s)
Mar 27 09:50:56 helium kernel:   Vendor: HP        Model: CD-Writer+ 9200   Rev: 1.0e
Mar 27 09:50:56 helium kernel:   Type:   CD-ROM                             ANSI SCSI revision: 04
Mar 27 09:50:56 helium scsi.agent[2085]: cdrom at /devices/pci0000:00/0000:00:1e.0/0000:02:04.0/host2/2:0:6:0
Mar 27 09:51:03 helium kernel: sr0: scsi3-mmc drive: 32x/32x writer cd/rw xa/form2 cdda tray

The tape drive works normally. But as soon as I try to use the CD drive-- by, for example, trying to mount or burn a CD-- my console and syslog begin to fill up with "dc395x: sg_to_virt failed!" messages-- several hundred per second. I can't unload the driver, and my system becomes sluggish. Once this starts I've often had to force a case reboot in order to restore normal operation. As you can imagine, I'm not happy about that.

I'm frustrated by this problem because the drive worked fine with earlier kernels. It definitely worked fine with 2.6.0-test4 and -test9. I don't want to go back to an earlier kernel, because of other security and hardware issues. My 2.6.3 kernel works perfectly, except that now my CD writer is broken.

Any help would be much appreciated. I'm willing to try any patches or diagnostics.

Thanks,
Andrew.

[...]

Yeah, this has been reported a few months back for the original driver in 2.4. I *think* I found and fixed what would have caused this problem in the latest version included in 2.6 but since no one has ever seen this issue in 2.6 it's been difficult to be certain.

[...]

There has been no changes to the in kernel dc395x driver between 2.6.0-test4 and 2.6.3.

First thing to try would be to upgrade to 2.6.5-rc1 (or newer) and see if that works any better.

If it still has issues then you should edit drivers/scsi/dc395x.c and uncomment the first "#define DEBUG_MASK" line, rebuild the dc395x module and then reload the module. You should then gets lots of debugging output in one of your log file which you can then gzip or bzip2 and then send directly to me.

 Jamie Lenehan <[email protected]>

[...]

Tried it with 2.6.5-rc2. Now 'modprobe dc395x' hangs (though without all of the 'sg_to_virt failed' messages) as the drive keeps spinning. 'reboot' also eventually hangs, and again I need to hit the case reset button to get back to normal. syslog shows "Unable to handle kernel NULL pointer dereference"-- see excerpt below. I'll try the debugging and send you a log soon.

Mar 28 22:40:10 helium kernel: dc395x: Tekram DC395(U/UW/F), DC315(U) - ASIC 
TRM-S1040 v2.05, 2004/03/08
Mar 28 22:40:11 helium kernel: dc395x: Used settings: AdapterID=07, Speed=0
(20.0MHz), dev_mode=0x77
Mar 28 22:40:11 helium kernel: dc395x:                AdaptMode=0x0f, Tags=4
(16), DelayReset=1s
Mar 28 22:40:11 helium kernel: dc395x: (Wide) Connectors: int50  Termination: 
Auto Low High 
Mar 28 22:40:11 helium kernel: dc395x: Performing initial SCSI bus reset
Mar 28 22:40:11 helium kernel: scsi2 : Tekram DC395(U/UW/F), DC315(U) - ASIC 
TRM-S1040 v2.05, 2004/03/08
Mar 28 22:40:12 helium kernel: dc395x: Target 02:  Sync: 100ns Offset 15 (10.0 
MB/s)
Mar 28 22:40:12 helium kernel:   Vendor: Seagate   Model: STT20000N         
Rev: 7A61
Mar 28 22:40:12 helium kernel:   Type:   Sequential-Access                  
ANSI SCSI revision: 02
Mar 28 22:40:12 helium scsi.agent[1795]: tape 
at /devices/pci0000:00/0000:00:1e.0/0000:02:04.0/host2/2:0:2:0
Mar 28 22:40:12 helium kernel: st: Version 20040226, fixed bufsize 32768, s/g 
segs 256
Mar 28 22:40:12 helium kernel: Unable to handle kernel NULL pointer 
dereference at virtual address 0000002e
Mar 28 22:40:12 helium kernel:  printing eip:
Mar 28 22:40:12 helium kernel: f8a961d7
Mar 28 22:40:12 helium kernel: *pde = 00000000
Mar 28 22:40:12 helium kernel: Oops: 0002 [#1]
Mar 28 22:40:12 helium kernel: PREEMPT SMP 
Mar 28 22:40:12 helium kernel: CPU:    0
Mar 28 22:40:12 helium kernel: EIP:    0060:[__crc_pm_idle+1598296/5541136]    
Not tainted
Mar 28 22:40:12 helium kernel: EFLAGS: 00010282   (2.6.5-rc2) 
Mar 28 22:40:12 helium kernel: EIP is at do_create_class_files+0x9a/0x152 [st]
Mar 28 22:40:12 helium kernel: eax: f73cd654   ebx: ffffffea   ecx: 00000000   
edx: f7fff2f0
Mar 28 22:40:12 helium kernel: esi: 00000000   edi: f73cd600   ebp: 00000000   
esp: f6811eb4
Mar 28 22:40:12 helium kernel: ds: 007b   es: 007b   ss: 0068
Mar 28 22:40:12 helium kernel: Process modprobe (pid: 1806, 
threadinfo=f6810000 task=f7c34300)
Mar 28 22:40:12 helium kernel: Stack: f7208b80 00900000 f76a0584 f8a96835 
f7493884 00000000 00000001 00000004 
Mar 28 22:40:12 helium kernel:        00000000 f73cd654 f8a9590c f73cd600 
00000000 00000000 00000000 c1b88480 
Mar 28 22:40:12 helium kernel:        c0189c97 f73cd654 00000000 c0189bb4 
f8a99e40 00000000 f73cd600 00000000 
Mar 28 22:40:12 helium kernel: Call Trace:
Mar 28 22:40:12 helium kernel:  [__crc_pm_idle+1596045/5541136] 
st_probe+0x506/0x883 [st]
Mar 28 22:40:12 helium kernel:  [create_dir+150/189] create_dir+0x96/0xbd
Mar 28 22:40:12 helium kernel:  [init_dir+0/31] init_dir+0x0/0x1f
Mar 28 22:40:12 helium kernel:  [bus_match+63/106] bus_match+0x3f/0x6a
Mar 28 22:40:12 helium kernel:  [driver_attach+86/128] driver_attach+0x56/0x80
Mar 28 22:40:12 helium kernel:  [bus_add_driver+140/159] 
bus_add_driver+0x8c/0x9f
Mar 28 22:40:12 helium kernel:  [__crc_pm_idle+549403/5541136] 
init_st+0x9a/0xe4 [st]
Mar 28 22:40:12 helium kernel:  [sys_init_module+304/603] 
sys_init_module+0x130/0x25b
Mar 28 22:40:12 helium kernel:  [syscall_call+7/11] syscall_call+0x7/0xb
Mar 28 22:40:12 helium kernel: 
Mar 28 22:40:12 helium kernel: Code: 89 43 44 89 1c 24 c7 44 24 04 a8 9f a9 f8 
e8 58 70 75 c7 89 
Mar 28 22:40:14 helium kernel:  <6>dc395x: Target 06:  Sync: 100ns Offset 15 
(10.0 MB/s)
Mar 28 22:40:14 helium kernel:   Vendor: HP        Model: CD-Writer+ 9200   
Rev: 1.0e
Mar 28 22:40:14 helium kernel:   Type:   CD-ROM                             
ANSI SCSI revision: 04
Mar 28 22:40:14 helium scsi.agent[1808]: how to add device type= 

at /devices/pci0000:00/0000:00:1e.0/0000:02:04.0/host2/2:0:6:0 ??

On Sun, Mar 28, 2004 at 11:03:02PM -0500, Andrew Schulman wrote:
[...]

Yeah, it's no longer getting to where you were having problems previously.

This is an unrelated problem. It's something to do with scsi tape sysfs support and it looks like a fix for this problem went in just after 2.6.5-rc2 was released (patch-2.6.5-rc2-bk2.bz2).

So you could wait for 2.6.5-rc3/2.6.5 to be released, upgrade to 2.6.5-rc3-bkx (where bkx is a bk snapshot with x >=2), or go back to the kernel you were using previously but copy the drivers/scsi/dc395x.c and drivers/scsi/dc395x.h from the 2.6.5-rc2 kernel into it.

 Jamie Lenehan <[email protected]>

Good news: my drive works properly now in 2.6.5-rc3. "sg_to_virt failed" messages are gone and the drive operates normally. Unfortunately, my nvidia driver won't compile in that kernel...

FYI, copying dc395x.{c,h} from 2.6.5-rc3 into 2.6.3 source didn't work. The driver built okay, but at insertion time I got error messages about unresolved symbols.

Anyway, it looks like you've corrected the CD drive problem. Thanks. Now I just hope the nvidia problem gets resolved by the time 2.6.5 is released.

Andrew.

I'm now running kernel 2.6.5. The good news is that my CD writer (HP 9200i) works again. The bad news is that I'm still getting e.g.

Apr  5 00:46:50 helium kernel: dc395x: sg_update_list: sg_to_virt failed
Apr  5 00:47:21 helium last message repeated 576 times
Apr  5 00:48:22 helium last message repeated 974 times
Apr  5 00:49:23 helium last message repeated 979 times
Apr  5 00:50:24 helium last message repeated 971 times
Apr  5 00:51:25 helium last message repeated 970 times
Apr  5 00:52:26 helium last message repeated 974 times
Apr  5 00:52:40 helium last message repeated 228 times

(result of burning a CD). This isn't great, but it's tolerable and at least the CD writer works again.

Andrew.

Have you verified that the CD(s) were actually written correctly? That's the one thing I'd really be concerned about. If so then you can always just comment the message out of the source code for now.

I'll look over that code again and see if I can see why it thinks it cannot find the address it's looking for (and if it matters).

What would be helpful (if your bored!) would be to enable the debugging at the top of dc395x.c and do a very short run (half a dozen copies of the message is enough, no need for 10k of them ;) and then compress the logs and put them somewhere I can grab them (or e-mail them if < 5MB).

Thanks.

 Jamie Lenehan <[email protected]>

Yes, I've used the CDs and they're fine.

Okay, I'll do this when I have time. A.