[sane-devel] Epson Perfection 3490 - first blood

Tue Sep 13 12:04:43 UTC 2005

Dear Friends,

Ok, running Linux 2.6.12-rc2, libusb-0.1.10a.

I just bought an Epson Perfection 3490.

Obtained esfw52.bin from installing it on an M$ PC (where the
scanner works like a charm, I must admit).

Then hooked it up to my Linux box, installed said firmware file
and installed sane-backends-2005-09-12.

Apparently some people got it working, but here are my experiences,
as output from the following short bug reporting script.

Anyone have any ideas where to start fiddling with the code?

Thanks.

bjd

---
#!/bin/sh
# bug reporting script

xx()
{
	echo "\$> $@"
	eval $@
	echo
} 2>&1

# unplug and power-cycle the scanner here, then:

xx strings -n 2 /usr/local/etc/sane.d/esfw52.bin \| tail -n 2

xx cat /proc/bus/usb/devices \| head -n 22

# first use -- this should cause a firmware upload:
export USB_DEBUG=255
export SANE_DEBUG_SNAPSCAN=255
xx scanimage -d snapscan:libusb:004:011 2>&1

xx udevinfo -a -p /sys/bus/usb/devices/4-11/

xx scanimage -L

xx sane-find-scanner

# during this the green 'ready' light blinks green,
# afterwards it is steady green again
export USB_DEBUG=255
export SANE_DEBUG_SNAPSCAN=255
xx scanimage -d snapscan:libusb:004:011 2>&1

# end bug reporting script
---

Output from bug reporting script:

$> strings -n 2 /usr/local/etc/sane.d/esfw52.bin | tail -n 2
EPSON   GT-F520         1.08
qThu Apr 14 2005 14:32

$> cat /proc/bus/usb/devices | head -n 22

T:  Bus=04 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#=  1 Spd=480 MxCh= 6
B:  Alloc=  0/800 us ( 0%), #Int=  0, #Iso=  0
D:  Ver= 2.00 Cls=09(hub  ) Sub=00 Prot=01 MxPS= 8 #Cfgs=  1
P:  Vendor=0000 ProdID=0000 Rev= 2.06
S:  Manufacturer=Linux 2.6.12-rc2 ehci_hcd
S:  Product=Intel Corporation 82801DB/DBM (ICH4/ICH4-M) USB2 EHCI Controller
S:  SerialNumber=0000:00:1d.7
C:* #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr=  0mA
I:  If#= 0 Alt= 0 #EPs= 1 Cls=09(hub  ) Sub=00 Prot=00 Driver=hub
E:  Ad=81(I) Atr=03(Int.) MxPS=   2 Ivl=256ms

T:  Bus=04 Lev=01 Prnt=01 Port=05 Cnt=01 Dev#= 11 Spd=480 MxCh= 0
D:  Ver= 2.00 Cls=ff(vend.) Sub=ff Prot=ff MxPS=64 #Cfgs=  1
P:  Vendor=04b8 ProdID=0122 Rev= 1.10
S:  Manufacturer=EPSON
S:  Product=EPSON Scanner
C:* #Ifs= 1 Cfg#= 1 Atr=c0 MxPwr=100mA
I:  If#= 0 Alt= 0 #EPs= 3 Cls=ff(vend.) Sub=ff Prot=ff Driver=(none)
E:  Ad=81(I) Atr=02(Bulk) MxPS= 512 Ivl=0ms
E:  Ad=02(O) Atr=02(Bulk) MxPS= 512 Ivl=0ms
E:  Ad=83(I) Atr=03(Int.) MxPS=   8 Ivl=4096ms

$> scanimage -d snapscan:libusb:004:011
[sanei_debug] Setting debug level of snapscan to 255.
[snapscan] sane_snapscan_init
[snapscan] sane_snapscan_init: Snapscan backend version 1.4.43
usb_set_debug: Setting debugging level to 255 (on)
usb_os_init: Found USB VFS at /proc/bus/usb
usb_os_find_busses: Found 004
usb_os_find_busses: Found 003
usb_os_find_busses: Found 002
usb_os_find_busses: Found 001
usb_os_find_busses: Skipping non bus directory devices
usb_os_find_devices: Found 011 on 004
usb_os_find_devices: Found 001 on 004
error obtaining child information: Inappropriate ioctl for device
usb_os_find_devices: Found 001 on 003
usb_os_find_devices: Found 004 on 002
skipped 1 class/vendor specific interface descriptors
usb_os_find_devices: Found 001 on 002
error obtaining child information: Inappropriate ioctl for device
usb_os_find_devices: Found 001 on 001
[snapscan] add_usb_device(libusb:004:011)
[snapscan] add_usb_device: Detected (kind of) an USB device
[snapscan] snapscani_usb_open(libusb:004:011)
[snapscan] add_usb_device: Checking if 0x04b8 is a supported USB vendor ID
[snapscan] snapscani_check_device()
[snapscan] mini_inquiry
[snapscan] snapscan_cmd
[snapscan] snapscani_usb_cmd(0,0xbff0cc20,6,0xbff0cbf0,0xbff0cbec (36))
[snapscan] atomic_usb_cmd(0,0xbff0cc20,6,0xbff0cbf0,0xbff0cbec (36))
[snapscan] usb_cmd(0,0xbff0cc20,6,0xbff0cbf0,0xbff0cbec (36))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x12 0x00 0x00 0x00 0x24 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read: reading:  0xf9 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] usb_read: reading:  0x06 0x00 0x02 0x02 0x49 0x00 0x00 0x00 0x45 0x50 ...
[snapscan] Read 36 bytes
[snapscan] usb_read: reading:  0xfb 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] snapscani_check_device: Is vendor "EPSON" model "EPSON Scanner" a supported scanner?
[snapscan] snapscani_get_model_id(EPSON Scanner, 0, 2)
[snapscan] snapscani_get_model_id: looking up scanner for ID 0x04b8,0x0122.
[snapscan] snapscani_get_model_id: scanner identified
[snapscan] snapscani_check_device: Autodetected driver: Perfection 3490
[snapscan] snapscani_usb_close(0)
[snapscan] 1st read 3 write 1
[snapscan] snapscani_usb_cmd(0,0xbff0cc20,6,0x0,0x0 (0))
[snapscan] atomic_usb_cmd(0,0xbff0cc20,6,0x0,0x0 (0))
[snapscan] usb_cmd(0,0xbff0cc20,6,0x0,0x0 (0))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read: reading:  0xfb 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] 2nd read 4 write 2
[snapscan] snapscani_init_device_structure()
[snapscan] sane_snapscan_open (libusb:004:011, 0xbff0de60)
[snapscan] find_device
[snapscan] sane_snapscan_open: Allocating 64512 bytes as scanner buffer.
[snapscan] sane_snapscan_open: allocated scanner structure at 0x80548e0
[snapscan] open_scanner
[snapscan] snapscani_usb_open(libusb:004:011)
[snapscan] sane_snapscan_open: waiting for scanner to warm up.
[snapscan] wait_scanner_ready
[snapscan] test_unit_ready
[snapscan] snapscan_cmd
[snapscan] snapscani_usb_cmd(0,0xbff0dc00,6,0x0,0x0 (0))
[snapscan] atomic_usb_cmd(0,0xbff0dc00,6,0x0,0x0 (0))
[snapscan] usb_cmd(0,0xbff0dc00,6,0x0,0x0 (0))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read: reading:  0xfb 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] sane_snapscan_open: performing scanner self test.
[snapscan] send_diagnostic
[snapscan] snapscan_cmd
[snapscan] snapscani_usb_cmd(0,0xbff0ddf0,6,0x0,0x0 (0))
[snapscan] atomic_usb_cmd(0,0xbff0ddf0,6,0x0,0x0 (0))
[snapscan] usb_cmd(0,0xbff0ddf0,6,0x0,0x0 (0))
[snapscan] sane_snapscan_open: self test passed.
[snapscan] inquiry
[snapscan] snapscan_cmd
[snapscan] snapscani_usb_cmd(0,0x8054910,6,0x8060748,0x8054a20 (120))
[snapscan] atomic_usb_cmd(0,0x8054910,6,0x8060748,0x8054a20 (120))
[snapscan] usb_cmd(0,0x8054910,6,0x8060748,0x8054a20 (120))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x12 0x00 0x00 0x00 0x78 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read: reading:  0xf9 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] usb_read: reading:  0x06 0x00 0x02 0x02 0x49 0x00 0x00 0x00 0x45 0x50 ...
[snapscan] Read 120 bytes
[snapscan] usb_read: reading:  0xfb 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] inquiry: exposure time: 0.0 ms
[snapscan] inquiry: ms per line: 0.000000
[snapscan] inquiry: G2R_DIFF: 0
[snapscan] inquiry: B2R_DIFF: 0
[snapscan] inquiry: Chroma offsets=0; Red=0, Green:=0, Blue=0
[snapscan] inquiry: hardware config = 0x00
[snapscan] inquiry: bits per pixel = 14
[snapscan] inquiry: pixels per scan line = 0
[snapscan] inquiry: bytes per scan line = 0
[snapscan] inquiry: number of scan lines = 0
[snapscan] inquiry: effective buffer size = 0 bytes, 0 lines
[snapscan] inquiry: expected total scan data: 0 bytes
[snapscan] pss->pdev->bus = 0x2, pss->hwst = 0x2
[snapscan] Looking up 34
[snapscan] Downloading /usr/local/etc/sane.d/esfw52.bin
[snapscan] Size of firmware: 63239
[snapscan] snapscan_cmd
[snapscan] snapscani_usb_cmd(0,0x8070350,63249,0x0,0x0 (0))
[snapscan] atomic_usb_cmd(0,0x8070350,63249,0x0,0x0 (0))
[snapscan] usb_cmd(0,0x8070350,63249,0x0,0x0 (0))
[snapscan] usb_cmd: cmdlen=10, datalen=63239
[snapscan] usb_write: writing:  0x2a 0x00 0x87 0x00 0x00 0x00 0x00 0xf7 0x07 0x00
[snapscan] Written 10 bytes
[snapscan] usb_read: reading:  0xf8 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] usb_write: writing:  0x02 0xf2 0xd5 0x32 0xff 0xff 0xff 0xff 0xff 0xff ...
[snapscan] Written 63239 bytes
[snapscan] usb_read: reading:  0xfb 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] wait_scanner_ready
[snapscan] test_unit_ready
[snapscan] snapscan_cmd
[snapscan] snapscani_usb_cmd(0,0xbff0dc00,6,0x0,0x0 (0))
[snapscan] atomic_usb_cmd(0,0xbff0dc00,6,0x0,0x0 (0))
[snapscan] usb_cmd(0,0xbff0dc00,6,0x0,0x0 (0))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read: reading:  0xfb 0x02 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] usb_request_sense
[snapscan] usb_cmd(0,0xbff0d8d0,6,0xbff0d8b0,0xbff0d8a4 (20))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x03 0x00 0x00 0x00 0x14 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read: reading:  0xf9 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] usb_read: reading:  0xf0 0x00 0x02 0x00 0x00 0x00 0x00 0x0b 0x00 0x00 ...
[snapscan] Read 20 bytes
[snapscan] usb_read: reading:  0xfb 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] sense_handler(0, 0xbff0d8b0, 0x80548e0)
[snapscan] sense_handler: sense key: 0x02, asc: 0x04, ascq: 0x01, i1: 0x08, i2: 0x00
[snapscan] sense_handler: Not ready.
[snapscan] sense_handler: Logical unit is in process of becoming ready. (8 seconds)
[snapscan] sense_handler: Not ready.
[snapscan] test_unit_ready: snapscan_cmd command failed: Device busy
[snapscan] Scanner warming up - waiting 9 seconds.
[snapscan] test_unit_ready
[snapscan] snapscan_cmd
[snapscan] snapscani_usb_cmd(0,0xbff0dc00,6,0x0,0x0 (0))
[snapscan] atomic_usb_cmd(0,0xbff0dc00,6,0x0,0x0 (0))
[snapscan] usb_cmd(0,0xbff0dc00,6,0x0,0x0 (0))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read: reading:  0xfb 0x02 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] usb_request_sense
[snapscan] usb_cmd(0,0xbff0d8d0,6,0xbff0d8b0,0xbff0d8a4 (20))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x03 0x00 0x00 0x00 0x14 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read: reading:  0xf9 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] usb_read: reading:  0xf0 0x00 0x02 0x00 0x00 0x00 0x00 0x0b 0x00 0x00 ...
[snapscan] Read 20 bytes
[snapscan] usb_read: reading:  0xfb 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] sense_handler(0, 0xbff0d8b0, 0x80548e0)
[snapscan] sense_handler: sense key: 0x02, asc: 0x04, ascq: 0x01, i1: 0x21, i2: 0x00
[snapscan] sense_handler: Not ready.
[snapscan] sense_handler: Logical unit is in process of becoming ready. (33 seconds)
[snapscan] sense_handler: Not ready.
[snapscan] test_unit_ready: snapscan_cmd command failed: Device busy
[snapscan] Scanner warming up - waiting 34 seconds.
[snapscan] test_unit_ready
[snapscan] snapscan_cmd
[snapscan] snapscani_usb_cmd(0,0xbff0dc00,6,0x0,0x0 (0))
[snapscan] atomic_usb_cmd(0,0xbff0dc00,6,0x0,0x0 (0))
[snapscan] usb_cmd(0,0xbff0dc00,6,0x0,0x0 (0))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read: reading:  0xfb 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] inquiry
[snapscan] snapscan_cmd
[snapscan] snapscani_usb_cmd(0,0x8054910,6,0x8060748,0x8054a20 (139))
[snapscan] atomic_usb_cmd(0,0x8054910,6,0x8060748,0x8054a20 (139))
[snapscan] usb_cmd(0,0x8054910,6,0x8060748,0x8054a20 (139))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x12 0x00 0x00 0x00 0x78 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read: reading:  0xf9 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] usb_read Only 120 bytes read
[snapscan] usb_read: reading:  0x06 0x00 0x02 0x02 0x49 0x00 0x00 0x00 0x45 0x50 ...
[snapscan] Read 120 bytes
[snapscan] inquiry: snapscan_cmd command failed: Error during device I/O
[snapscan] sane_snapscan_open: inquiry after firmware upload command failed: Error during device I/O
scanimage: open of device snapscan:libusb:004:011 failed: Error during device I/O
[snapscan] sane_snapscan_exit

$> udevinfo -a -p /sys/bus/usb/devices/4-11/
couldn't get the class device

$> scanimage -L
[sanei_debug] Setting debug level of snapscan to 255.
[snapscan] sane_snapscan_init
[snapscan] sane_snapscan_init: Snapscan backend version 1.4.43
usb_set_debug: Setting debugging level to 255 (on)
usb_os_init: Found USB VFS at /proc/bus/usb
usb_os_find_busses: Found 004
usb_os_find_busses: Found 003
usb_os_find_busses: Found 002
usb_os_find_busses: Found 001
usb_os_find_busses: Skipping non bus directory devices
usb_os_find_devices: Found 011 on 004
usb_os_find_devices: Found 001 on 004
error obtaining child information: Inappropriate ioctl for device
usb_os_find_devices: Found 001 on 003
usb_os_find_devices: Found 004 on 002
skipped 1 class/vendor specific interface descriptors
usb_os_find_devices: Found 001 on 002
error obtaining child information: Inappropriate ioctl for device
usb_os_find_devices: Found 001 on 001
[snapscan] add_usb_device(libusb:004:011)
[snapscan] add_usb_device: Detected (kind of) an USB device
[snapscan] snapscani_usb_open(libusb:004:011)
[snapscan] add_usb_device: Checking if 0x04b8 is a supported USB vendor ID
[snapscan] snapscani_check_device()
[snapscan] mini_inquiry
[snapscan] snapscan_cmd
[snapscan] snapscani_usb_cmd(0,0xbfafe260,6,0xbfafe230,0xbfafe22c (36))
[snapscan] atomic_usb_cmd(0,0xbfafe260,6,0xbfafe230,0xbfafe22c (36))
[snapscan] usb_cmd(0,0xbfafe260,6,0xbfafe230,0xbfafe22c (36))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x12 0x00 0x00 0x00 0x24 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read Only 0 bytes read
[snapscan] usb_read: reading:  0x06 0x00 0x02 0x02 0x49 0x00 0x00 0x00
[snapscan] Read 0 bytes
[snapscan] mini_inquiry: snapscan_cmd command failed: Error during device I/O
[snapscan] snapscani_check_device: mini_inquiry failed with Error during device I/O.
[snapscan] snapscani_usb_close(0)
[snapscan] 1st read 0 write 1
[snapscan] snapscani_usb_cmd(0,0xbfafe1b0,6,0xbfafe130,0xbfafe120 (120))
[snapscan] atomic_usb_cmd(0,0xbfafe1b0,6,0xbfafe130,0xbfafe120 (120))
[snapscan] usb_cmd(0,0xbfafe1b0,6,0xbfafe130,0xbfafe120 (120))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x12 0x00 0x00 0x00 0x78 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read: reading:  0xf9 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] usb_read: reading:  0x06 0x00 0x02 0x02 0x49 0x00 0x00 0x00 0x45 0x50 ...
[snapscan] Read 120 bytes
[snapscan] usb_read: reading:  0xfb 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] 2nd read 4 write 2
[snapscan] sane_snapscan_get_devices (0xbfaff494, 0)
[snapscan] sane_snapscan_exit

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).

$> sane-find-scanner
usb_set_debug: Setting debugging level to 255 (on)
usb_os_init: Found USB VFS at /proc/bus/usb
usb_os_find_busses: Found 004
usb_os_find_busses: Found 003
usb_os_find_busses: Found 002
usb_os_find_busses: Found 001
usb_os_find_busses: Skipping non bus directory devices
usb_os_find_devices: Found 011 on 004
usb_os_find_devices: Found 001 on 004
error obtaining child information: Inappropriate ioctl for device
usb_os_find_devices: Found 001 on 003
usb_os_find_devices: Found 004 on 002
skipped 1 class/vendor specific interface descriptors
usb_os_find_devices: Found 001 on 002
error obtaining child information: Inappropriate ioctl for device
usb_os_find_devices: Found 001 on 001

  # sane-find-scanner will now attempt to detect your scanner. If the
  # result is different from what you expected, first make sure your
  # scanner is powered up and properly connected to your computer.

  # No SCSI scanners found. If you expected something different, make sure that
  # you have loaded a SCSI driver for your SCSI adapter.

found USB scanner (vendor=0x04b8 [EPSON], product=0x0122 [EPSON Scanner]) at libusb:004:011
  # Your USB scanner was (probably) detected. It may or may not be supported by
  # SANE. Try scanimage -L and read the backend's manpage.

  # Not checking for parallel port scanners.

  # Most Scanners connected to the parallel port or other proprietary ports
  # can't be detected by this program.

$> scanimage -d snapscan:libusb:004:011
[sanei_debug] Setting debug level of snapscan to 255.
[snapscan] sane_snapscan_init
[snapscan] sane_snapscan_init: Snapscan backend version 1.4.43
usb_set_debug: Setting debugging level to 255 (on)
usb_os_init: Found USB VFS at /proc/bus/usb
usb_os_find_busses: Found 004
usb_os_find_busses: Found 003
usb_os_find_busses: Found 002
usb_os_find_busses: Found 001
usb_os_find_busses: Skipping non bus directory devices
usb_os_find_devices: Found 011 on 004
usb_os_find_devices: Found 001 on 004
error obtaining child information: Inappropriate ioctl for device
usb_os_find_devices: Found 001 on 003
usb_os_find_devices: Found 004 on 002
skipped 1 class/vendor specific interface descriptors
usb_os_find_devices: Found 001 on 002
error obtaining child information: Inappropriate ioctl for device
usb_os_find_devices: Found 001 on 001
[snapscan] add_usb_device(libusb:004:011)
[snapscan] add_usb_device: Detected (kind of) an USB device
[snapscan] snapscani_usb_open(libusb:004:011)
[snapscan] add_usb_device: Checking if 0x04b8 is a supported USB vendor ID
[snapscan] snapscani_check_device()
[snapscan] mini_inquiry
[snapscan] snapscan_cmd
[snapscan] snapscani_usb_cmd(0,0xbf85ebb0,6,0xbf85eb80,0xbf85eb7c (36))
[snapscan] atomic_usb_cmd(0,0xbf85ebb0,6,0xbf85eb80,0xbf85eb7c (36))
[snapscan] usb_cmd(0,0xbf85ebb0,6,0xbf85eb80,0xbf85eb7c (36))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x12 0x00 0x00 0x00 0x24 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read: reading:  0xf9 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] usb_read: reading:  0x06 0x00 0x02 0x02 0x49 0x00 0x00 0x00 0x45 0x50 ...
[snapscan] Read 36 bytes
[snapscan] usb_read: reading:  0xfb 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] snapscani_check_device: Is vendor "EPSON" model "EPSON Scanner1" a supported scanner?
[snapscan] snapscani_get_model_id(EPSON Scanner1, 0, 2)
[snapscan] snapscani_get_model_id: looking up scanner for ID 0x04b8,0x0122.
[snapscan] snapscani_get_model_id: scanner identified
[snapscan] snapscani_check_device: Autodetected driver: Perfection 3490
[snapscan] snapscani_usb_close(0)
[snapscan] 1st read 3 write 1
[snapscan] snapscani_usb_cmd(0,0xbf85ebb0,6,0x0,0x0 (0))
[snapscan] atomic_usb_cmd(0,0xbf85ebb0,6,0x0,0x0 (0))
[snapscan] usb_cmd(0,0xbf85ebb0,6,0x0,0x0 (0))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read: reading:  0xfb 0x02 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] usb_read_status: scanner structure not set, returning default error
[snapscan] 2nd read 4 write 2
[snapscan] snapscani_init_device_structure()
[snapscan] sane_snapscan_open (libusb:004:011, 0xbf85fdf0)
[snapscan] find_device
[snapscan] sane_snapscan_open: Allocating 64512 bytes as scanner buffer.
[snapscan] sane_snapscan_open: allocated scanner structure at 0x80548e0
[snapscan] open_scanner
[snapscan] snapscani_usb_open(libusb:004:011)
[snapscan] sane_snapscan_open: waiting for scanner to warm up.
[snapscan] wait_scanner_ready
[snapscan] test_unit_ready
[snapscan] snapscan_cmd
[snapscan] snapscani_usb_cmd(0,0xbf85fb90,6,0x0,0x0 (0))
[snapscan] atomic_usb_cmd(0,0xbf85fb90,6,0x0,0x0 (0))
[snapscan] usb_cmd(0,0xbf85fb90,6,0x0,0x0 (0))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read: reading:  0xfb 0x02 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] usb_request_sense
[snapscan] usb_cmd(0,0xbf85f860,6,0xbf85f840,0xbf85f834 (20))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x03 0x00 0x00 0x00 0x14 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read: reading:  0xf9 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] usb_read: reading:  0xf0 0x00 0x02 0x00 0x00 0x00 0x00 0x0b 0x00 0x00 ...
[snapscan] Read 20 bytes
[snapscan] usb_read: reading:  0xfb 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] sense_handler(0, 0xbf85f840, 0x80548e0)
[snapscan] sense_handler: sense key: 0x02, asc: 0x04, ascq: 0x01, i1: 0x08, i2: 0x00
[snapscan] sense_handler: Not ready.
[snapscan] sense_handler: Logical unit is in process of becoming ready. (8 seconds)
[snapscan] sense_handler: Not ready.
[snapscan] test_unit_ready: snapscan_cmd command failed: Device busy
[snapscan] Scanner warming up - waiting 9 seconds.
[snapscan] test_unit_ready
[snapscan] snapscan_cmd
[snapscan] snapscani_usb_cmd(0,0xbf85fb90,6,0x0,0x0 (0))
[snapscan] atomic_usb_cmd(0,0xbf85fb90,6,0x0,0x0 (0))
[snapscan] usb_cmd(0,0xbf85fb90,6,0x0,0x0 (0))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read: reading:  0xfb 0x02 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] usb_request_sense
[snapscan] usb_cmd(0,0xbf85f860,6,0xbf85f840,0xbf85f834 (20))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x03 0x00 0x00 0x00 0x14 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read: reading:  0xf9 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] usb_read: reading:  0xf0 0x00 0x02 0x00 0x00 0x00 0x00 0x0b 0x00 0x00 ...
[snapscan] Read 20 bytes
[snapscan] usb_read: reading:  0xfb 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] sense_handler(0, 0xbf85f840, 0x80548e0)
[snapscan] sense_handler: sense key: 0x02, asc: 0x04, ascq: 0x01, i1: 0x20, i2: 0x00
[snapscan] sense_handler: Not ready.
[snapscan] sense_handler: Logical unit is in process of becoming ready. (32 seconds)
[snapscan] sense_handler: Not ready.
[snapscan] test_unit_ready: snapscan_cmd command failed: Device busy
[snapscan] Scanner warming up - waiting 33 seconds.
[snapscan] test_unit_ready
[snapscan] snapscan_cmd
[snapscan] snapscani_usb_cmd(0,0xbf85fb90,6,0x0,0x0 (0))
[snapscan] atomic_usb_cmd(0,0xbf85fb90,6,0x0,0x0 (0))
[snapscan] usb_cmd(0,0xbf85fb90,6,0x0,0x0 (0))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read: reading:  0xfb 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] sane_snapscan_open: performing scanner self test.
[snapscan] send_diagnostic
[snapscan] snapscan_cmd
[snapscan] snapscani_usb_cmd(0,0xbf85fd80,6,0x0,0x0 (0))
[snapscan] atomic_usb_cmd(0,0xbf85fd80,6,0x0,0x0 (0))
[snapscan] usb_cmd(0,0xbf85fd80,6,0x0,0x0 (0))
[snapscan] sane_snapscan_open: self test passed.
[snapscan] inquiry
[snapscan] snapscan_cmd
[snapscan] snapscani_usb_cmd(0,0x8054910,6,0x8060748,0x8054a20 (120))
[snapscan] atomic_usb_cmd(0,0x8054910,6,0x8060748,0x8054a20 (120))
[snapscan] usb_cmd(0,0x8054910,6,0x8060748,0x8054a20 (120))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x12 0x00 0x00 0x00 0x78 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read: reading:  0xf9 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] usb_read: reading:  0x06 0x00 0x02 0x02 0x49 0x00 0x00 0x00 0x45 0x50 ...
[snapscan] Read 120 bytes
[snapscan] usb_read: reading:  0xfb 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] inquiry: exposure time: /./ ms
[snapscan] inquiry: ms per line: 0.000000
[snapscan] inquiry: G2R_DIFF: 0
[snapscan] inquiry: B2R_DIFF: 0
[snapscan] inquiry: Chroma offsets=0; Red=0, Green:=0, Blue=0
[snapscan] inquiry: hardware config = 0xbd
[snapscan] inquiry: bits per pixel = 14
[snapscan] inquiry: pixels per scan line = 14240
[snapscan] inquiry: bytes per scan line = 14240
[snapscan] inquiry: number of scan lines = 0
[snapscan] inquiry: effective buffer size = 0 bytes, 0 lines
[snapscan] inquiry: expected total scan data: 0 bytes
[snapscan] pss->pdev->bus = 0x2, pss->hwst = 0x0
[snapscan] close_scanner
[snapscan] snapscani_usb_close(0)
[snapscan] 1st read 13 write 6
[snapscan] snapscani_usb_cmd(0,0xbf85fb70,6,0xbf85faf0,0xbf85fa54 (120))
[snapscan] atomic_usb_cmd(0,0xbf85fb70,6,0xbf85faf0,0xbf85fa54 (120))
[snapscan] usb_cmd(0,0xbf85fb70,6,0xbf85faf0,0xbf85fa54 (120))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x12 0x00 0x00 0x00 0x78 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read: reading:  0xf9 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] usb_read: reading:  0x06 0x00 0x02 0x02 0x49 0x00 0x00 0x00 0x45 0x50 ...
[snapscan] Read 120 bytes
[snapscan] usb_read: reading:  0xfb 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] snapscani_usb_cmd(0,0xbf85fb80,6,0x0,0x0 (0))
[snapscan] atomic_usb_cmd(0,0xbf85fb80,6,0x0,0x0 (0))
[snapscan] usb_cmd(0,0xbf85fb80,6,0x0,0x0 (0))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read: reading:  0xfb 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] 2nd read 18 write 8
[snapscan] alloc_gamma_tables: using 4*16384 bytes for gamma table
[snapscan] sane_snapscan_control_option (0x80548e0, 0, 0, 0xbf85fef0, (nil))
[snapscan] sane_snapscan_control_option (0x80548e0, 0, 0, 0xbf85fe08, (nil))
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 0)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 1)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 2)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 3)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 4)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 5)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 6)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 7)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 8)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 9)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 10)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 11)
[snapscan] sane_snapscan_control_option (0x80548e0, 11, 0, 0x8053b98, (nil))
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 12)
[snapscan] sane_snapscan_control_option (0x80548e0, 12, 0, 0x8053b9c, (nil))
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 13)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 14)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 15)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 16)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 17)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 18)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 19)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 20)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 21)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 22)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 23)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 24)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 25)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 26)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 27)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 28)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 29)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 30)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 31)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 32)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 33)
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 34)
[snapscan] sane_snapscan_control_option (0x80548e0, 9, 0, 0xbf85fe04, (nil))
[snapscan] sane_snapscan_control_option (0x80548e0, 10, 0, 0xbf85fe04, (nil))
[snapscan] sane_snapscan_control_option (0x80548e0, 9, 0, 0xbf85feec, (nil))
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 11)
[snapscan] sane_snapscan_control_option (0x80548e0, 11, 1, 0xbf85fee8, 0xbf85fe08)
[snapscan] sane_snapscan_control_option: option br-x set to value [snapscan] other than an integer or boolean.
[snapscan] sane_snapscan_control_option (0x80548e0, 10, 0, 0xbf85feec, (nil))
[snapscan] sane_snapscan_get_option_descriptor (0x80548e0, 12)
[snapscan] sane_snapscan_control_option (0x80548e0, 12, 1, 0xbf85fee8, 0xbf85fe08)
[snapscan] sane_snapscan_control_option: option br-y set to value [snapscan] other than an integer or boolean.
[snapscan] sane_snapscan_start (0x80548e0)
[snapscan] open_scanner
[snapscan] snapscani_usb_open(libusb:004:011)
[snapscan] wait_scanner_ready
[snapscan] test_unit_ready
[snapscan] snapscan_cmd
[snapscan] snapscani_usb_cmd(0,0xbf85fcd0,6,0x0,0x0 (0))
[snapscan] atomic_usb_cmd(0,0xbf85fcd0,6,0x0,0x0 (0))
[snapscan] usb_cmd(0,0xbf85fcd0,6,0x0,0x0 (0))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read: reading:  0xfb 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] reserve_unit
[snapscan] snapscan_cmd
[snapscan] snapscani_usb_cmd(0,0xbf85fdc0,6,0x0,0x0 (0))
[snapscan] atomic_usb_cmd(0,0xbf85fdc0,6,0x0,0x0 (0))
[snapscan] usb_cmd(0,0xbf85fdc0,6,0x0,0x0 (0))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x16 0x00 0x00 0x00 0x00 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read: reading:  0xfb 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] set_window
[snapscan] set_window Resolution: 300
[snapscan] set_window Width:  13606
[snapscan] set_window Length: 18708
[snapscan] set_window Mode: 0
[snapscan] set_window: bits-per-pixel set to 8
[snapscan] set_window: operation mode set to 0xc0
[snapscan] snapscan_cmd
[snapscan] snapscani_usb_cmd(0,0x8054910,66,0x0,0x0 (0))
[snapscan] atomic_usb_cmd(0,0x8054910,66,0x0,0x0 (0))
[snapscan] usb_cmd(0,0x8054910,66,0x0,0x0 (0))
[snapscan] usb_cmd: cmdlen=10, datalen=56
[snapscan] usb_write: writing:  0x24 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x38 0x00
[snapscan] Written 10 bytes
[snapscan] usb_read: reading:  0xf8 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] usb_write: writing:  0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x30 0x00 0x00 ...
[snapscan] Written 56 bytes
[snapscan] usb_read: reading:  0xfb 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] inquiry
[snapscan] snapscan_cmd
[snapscan] snapscani_usb_cmd(0,0x8054910,6,0x8060748,0x8054a20 (139))
[snapscan] atomic_usb_cmd(0,0x8054910,6,0x8060748,0x8054a20 (139))
[snapscan] usb_cmd(0,0x8054910,6,0x8060748,0x8054a20 (139))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x12 0x00 0x00 0x00 0x78 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read: reading:  0xf9 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] usb_read Only 120 bytes read
[snapscan] usb_read: reading:  0x06 0x00 0x02 0x02 0x49 0x00 0x00 0x00 0x45 0x50 ...
[snapscan] Read 120 bytes
[snapscan] inquiry: snapscan_cmd command failed: Error during device I/O
[snapscan] sane_snapscan_start: inquiry command failed: Error during device I/O
scanimage: sane_start: Error during device I/O
[snapscan] sane_snapscan_cancel
[snapscan] release_unit
[snapscan] snapscan_cmd
[snapscan] snapscani_usb_cmd(0,0xbf85fd30,6,0x0,0x0 (0))
[snapscan] atomic_usb_cmd(0,0xbf85fd30,6,0x0,0x0 (0))
[snapscan] usb_cmd(0,0xbf85fd30,6,0x0,0x0 (0))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x17 0x00 0x00 0x00 0x00 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read: reading:  0x17 0x00 0x00 0x00 0x00 0x00 0xfc 0xc3
[snapscan] Read 8 bytes
[snapscan] usb_cmd: The transaction should now be completed, but the scanner has more data to send[snapscan] release_unit: scsi command error: Error during device I/O
[snapscan] close_scanner
[snapscan] snapscani_usb_close(0)
[snapscan] 1st read 8 write 13
[snapscan] snapscani_usb_cmd(0,0xbf85fc20,6,0xbf85fba0,0xbf85fb90 (120))
[snapscan] atomic_usb_cmd(0,0xbf85fc20,6,0xbf85fba0,0xbf85fb90 (120))
[snapscan] usb_cmd(0,0xbf85fc20,6,0xbf85fba0,0xbf85fb90 (120))
[snapscan] usb_cmd: cmdlen=6, datalen=0
[snapscan] usb_write: writing:  0x12 0x00 0x00 0x00 0x78 0x00
[snapscan] Written 6 bytes
[snapscan] usb_read: reading:  0xf9 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] usb_read: reading:  0x06 0x00 0x02 0x02 0x49 0x00 0x00 0x00 0x45 0x50 ...
[snapscan] Read 120 bytes
[snapscan] usb_read: reading:  0xfb 0x00 0x00 0x00 0x00 0x00 0x00 0x00
[snapscan] Read 8 bytes
[snapscan] 2nd read 12 write 14
[snapscan] sane_snapscan_close (0x80548e0)
[snapscan] close_scanner
[snapscan] sane_snapscan_exit

End of output
---

Several notes:

Note 1.
-------
`udevinfo -a -p /sys/bus/usb/devices/4-11/' in the script
could not get the class device.
I had plugged and unplugged the scanner in and out a couple
of times before, and the /sys entry is still an older one,
4-6, not 4-11:

$> udevinfo -a -p /sys/bus/usb/devices/4-6/
udevinfo starts with the device the node belongs to and then walks up the
device chain, to print for every device found, all possibly useful attributes
in the udev key format.
Only attributes within one device section may be used together in one rule,
to match the device for which the node will be created.

  looking at class device '/sys/bus/usb/devices/4-6':
    SUBSYSTEM=="unknown"
    SYSFS{bConfigurationValue}=="1"
    SYSFS{bDeviceClass}=="ff"
    SYSFS{bDeviceProtocol}=="ff"
    SYSFS{bDeviceSubClass}=="ff"
    SYSFS{bMaxPower}=="100mA"
    SYSFS{bNumConfigurations}=="1"
    SYSFS{bNumInterfaces}==" 1"
    SYSFS{bcdDevice}=="0110"
    SYSFS{bmAttributes}=="c0"
    SYSFS{configuration}==""
    SYSFS{detach_state}=="0"
    SYSFS{devnum}=="8"
    SYSFS{idProduct}=="0122"
    SYSFS{idVendor}=="04b8"
    SYSFS{manufacturer}=="EPSON"
    SYSFS{maxchild}=="0"
    SYSFS{product}=="EPSON Scanner"
    SYSFS{speed}=="480"
    SYSFS{version}==" 2.00"

Note 2.
-------
snapscani_check_device() sometimes reports:
Is vendor "EPSON" model "EPSON Scanner" a supported scanner?
while at other times:
Is vendor "EPSON" model "EPSON Scanner1" a supported scanner?
                                      ^
Note 3.
-------
Device busy and I/O errors in `scanimage'.
Obviously there's just error output, no scanning output.