[sane-devel] scanimage fails with ACARD AEC-6712TS and HP ScanJet 4c (SCSI)

Tue Apr 26 07:33:40 UTC 2011

Hi,

When I do sane-find-scanner as root, it detects my scanner:  found
SCSI processor "HP C2520A 3503" at /dev/sg0
But when I try scanimage -L as root, it pauses for a long time, then
the scanner is set offline and sane-find-scanner no longer detects it.
I tried the same hardware and connections in Windows 98 and it worked.

Here is my system information:
uname -a: Linux hotrod 2.6.35-22-generic #33-Ubuntu SMP Sun Sep 19
20:34:50 UTC 2010 i686 GNU/Linux

The SCSI adapter is an ACARD AEC-6712TS (PCI Ultra SCSI), with an
internal 50 pin connector (unused), and external high density 50 pin
connector (used). Detected as "Artop Electronic Corp AEC6712S SCSI
(rev 08)", and it uses the Linux "atp870u" driver. The card
documentation claims it does "automatic" SCSI termination. This is
what the kernel prints on boot:
[    0.861732] atp870u 0000:00:0c.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
[    0.861739] atp870u: use 32bit DMA mask.
[    0.861745]    ACARD AEC-671X PCI Ultra/W SCSI-2/3 Host Adapter: 0
IO:c000, IRQ:16.
...
[    0.981966]          ID:  5  HP      C2520A          3503
[    0.981966]          ID:  7  Host Adapter

The scanner is an HP ScanJet 4c, SCSI ID 5, with termination set,
connected via a high density 50 pin to Centronics 50 pin cable. I
tried booting with the scanner SCSI termination set either way, but it
made no difference.

Here is the output from scanimage -L:
SANE_DEBUG_HP=255 scanimage -d /dev/sg0 -vvvvv -L
[sanei_debug] Setting debug level of hp to 255.
[hp] sane_init called
[hp] hp_init: global.is_up = 1
[hp] sane_init will finish with Success
[hp] sane_get_devices called
[hp] hp_read_config: hp backend v1.06/$Revision$ starts reading config file
[hp] hp_read_config: processing line <scsi HP>
[hp] hp_read_config: processing line <# Uncomment the following if you
have "Error during device I/O" on SCSI>
[hp] hp_read_config: processing line <#   option dumb-read>
[hp] hp_read_config: processing line <#>
[hp] hp_read_config: processing line <# The usual place for a
SCSI-scanner on Linux>
[hp] hp_read_config: processing line </dev/scanner>
[hp] hp_attach_matching_devices: attach matching scsi HP
[hp] hp_attach: "/dev/sg0"
[hp] sanei_hp_device_info_get: searching /dev/sg0
[hp] sanei_hp_device_info_get: check /dev/sg0
[hp] hp_get_dev: New device /dev/sg0, connect-scsi, scsi-request=1
[hp] sanei_hp_device_new: /dev/sg0
[hp] sanei_hp_device_info_get: searching /dev/sg0
[hp] sanei_hp_device_info_get: check /dev/sg0
[hp] sanei_hp_device_info_get: searching /dev/sg0
[hp] sanei_hp_device_info_get: check /dev/sg0
[hp] hp_GetOpenDevice: device /dev/sg0 not open
[hp] scsi_inquire: sending INQUIRE
[hp] vendor=HP      , model=C2520A          , rev=3503
[hp] scsi_new: sending TEST_UNIT_READY
[hp] hp_AddOpenDevice: /dev/sg0 should not be kept open
[hp] scsi_flush: writing 2 bytes:
[hp]  0x0000  1B 45                                            .E
[hp] sanei_hp_device_info_get: searching /dev/sg0
[hp] sanei_hp_device_info_get: check /dev/sg0

...pauses here for a long time...

[hp] sanei_hp_device_new: SCL reset failed
[hp] scsi_close: closing fd 5
[hp] sanei_hp_device_info_get: searching /dev/sg0
[hp] sanei_hp_device_info_get: check /dev/sg0
[hp] scsi_close: really closed
[hp] hp_RemoveOpenFd: 5 not removed
... I cut some text here which didn't seem relevant ...
[hp] hp_read_config: reset to default config
[hp] sane_get_devices will finish with Success

No scanners were identified. If you were expecting something different,
check that the scanner is plugged in, turned on and detected by the
sane-find-scanner tool (if appropriate). Please read the documentation
which came with this software (README, FAQ, manpages).
[hp] sane_exit called
[hp] hp_destroy: global.is_up = 0
[hp] sane_exit will finish

After running the scanimage -L, I see this in dmesg:
[  758.240030]  atp870u: abort Channel = 0
[  758.240036] working=1 last_cmd=5  quhdu=7 quendu=7  r 0= 6 r 1=2c r
2=cf r 3= a r 4= 0 r 5= 0 r 6= 0 r 7= 2 r 8= 0 r 9= 0 r a= 0 r b= 0 r
c= 0 r d= 0 r e= 0 r f= 0 r10=36 r11=20 r12= 0 r13= 0 r14= 2 r15=25
r16=80 r17=16 r1c=a0 r1f=37 in_snd= 0  d00= 1 d02= 8
[  758.240091]  que cdb=   a   0   0   0   2   0  last_lenu= 2
atp870u: abort Channel = 0
[  768.240040] working=1 last_cmd=5  quhdu=7 quendu=8  r 0= 6 r 1=2c r
2=cf r 3= a r 4= 0 r 5= 0 r 6= 0 r 7= 2 r 8= 0 r 9= 0 r a= 0 r b= 0 r
c= 0 r d= 0 r e= 0 r f= 0 r10=36 r11=20 r12= 0 r13= 0 r14= 2 r15=25
r16=80 r17=16 r1c=a0 r1f=37 in_snd= 0  d00= 1 d02= 8
[  768.240108]  que cdb=   0   0   0   0   0   0  last_lenu= 2
[  768.240133] scsi 0:0:5:0: Device offlined - not ready after error recovery

One thing I found interesting was the output of lsscsi -lll  (this
output is prior to the device being offlined, so state=running rather
than state=offline). Rather than putting /dev/sg0 for the dev name it
simply puts "-". I don't know if this is related to the problem at all
or simply a quirk of lsscsi, but just in case:
[0:0:5:0]    process HP       C2520A           3503  -
  device_blocked=0
  iocounterbits=32
  iodone_cnt=0x3
  ioerr_cnt=0x0
  iorequest_cnt=0x3
  queue_depth=1
  queue_type=none
  scsi_level=3
  state=running
  timeout=0
  type=3

Since I know that the card, cable, and scanner work, I figure it's
either a problem in sane or with the SCSI card support under Linux (or
maybe some combination effect?), but I'm not sure how to tell. I also
noticed a similar-looking problem from 2006:
http://lists.alioth.debian.org/pipermail/sane-devel/2006-August/017549.html

Thanks a lot for any suggestions or ideas,
Jeff