Hoping that someone here may be able to solve this paradox, I've prepared
the following report, comparing captured stderr output (with
SANE_DEBUG_SANEI_SCSI and SANE_DEBUG_MICROTEK each set = 32) from a
successful II-G run, to that produced by a failed E3 attempt. I apologize
in advance for the length, but without it, the few differences between them
would be difficult to place in context. To save space (and spare everyone
a lot of redundant stuff), I've merged the 2 logs into a single annotated
report. If 2 completely separate logs would be more convenient, and/or
different SANE_DEBUG_xxx levels, just let me know.
Yuri and I will both be following this thread, so that I can respond to
suggestions for further tests, etc., and so that he can clarify which
modules were (and/or, were *not*) modified in porting SANE to the OS/2
environment.
"A Tale of Two Scanners": Microtek 300 dpi scanners and SANE[OS2] 1.01
SYNOPSIS OF PROBLEM:
The E3 makes a series of short, slow-speed moves, then a brief,
high-pitch whine (fast return to home postion, following precal?)
Immediately after that short move, SCANIMAGE fails with a "Device I/O
error".
The IIG makes a similar sequence of startup noises, but then performs a
normal scan. {Unfortunately, the II-G lacks several features found in the
E3 - such as color.)
In the hope that someone can identify the source of SANE[OS2]'s problems
with the E3, this report presents excerpted "stderr" output from
comparative runs made on the same system.
TEST CONDITIONS
All tests reported here were run with the same SCSI adapter (AHA1502AE,
supplied with the E3). The two scanners were "swapped" by manually moving
the cable connection (each device is actually set to SCSI ID 4). The
scanner _is_ seen by find-scanner.
The following SCANIMAGE command-line was used in all tests, in each case
with " 2>" appended to capture stderr in a text file:
"scanimage -d microtek:b0t4l0 -x 100 -y 100 --mode Gray "
The "microtek.conf" file contained 2 lines:
#noprecal
b0t4l0
(I have tested the E3 both with and without "#noprecal", but it seems to
make no difference; even when present, it seems to be ignored.)
The captured stderr logs were generated by these environment settings:
SET SANE_DEBUG_MICROTEK=32
SET SANE_DEBUG_SANEI_SCSI=32
Editing changes made to the raw stderr logs:
(1) Each log contained a small number of 0x1A characters; for
readability in all environments, they have been replaced in
the text below by "{Ctl-Z}".
(2) Comments interspersed in the log text are enclosed in {}, with
the boundaries between commentary and log-content marked by
lines of asterisks.
(3) Duplicated blocks of text removed in some cases; all such
deletions are noted.
{The first block of output is identical between the IIG and E3, except of
course for the name of the temporary file created, and the model-ID
returned by the device:}
*****************************************************************
[sanei_init_debug]: Setting debug level of microtek to 32.
[microtek] sane_init: MICROTEK says hello! (v0.10.1)
[microtek] sane_init: config- #noprecal
[microtek] sane_init: config- b0t4l0
[microtek] attach_scanner: b0t4l0
[microtek] attach_scanner: opening b0t4l0
[sanei_init_debug]: Setting debug level of sanei_scsi to 32.
[sanei_scsi] OS/2: installed adapters 1
*****
{Consider this "Point A": }
****
[sanei_scsi] OS/2: ASPI manager is 'OS2ASPI Dev Mgr AHA-1520/1522 '
[sanei_scsi] OS/2: host adapter is 'AHA-1520/1522 '
[sanei_scsi] OS/2: unique id is ''
[sanei_scsi] open_aspi: open temporary file 'asa00225'
[sanei_scsi] OS/2: adapter#00 'AHA-1520/1522 '
[sanei_scsi] OS/2: id#00 status=82h
[sanei_scsi] OS/2: id#01 status=82h
[sanei_scsi] OS/2: id#02 status=82h
[sanei_scsi] OS/2: id#03 status=82h
[sanei_scsi] OS/2: id#04 status=01h
[sanei_scsi] OS/2: type is 'scanner'
[sanei_scsi] OS/2 'MICROTEKScanMakerIIG 6001.01SCSI FW81193
CLJ1116ŒÅîX'
[sanei_scsi] OS/2: id#05 status=82h
[sanei_scsi] OS/2: id#06 status=82h
[sanei_scsi] open_aspi: close temporary file 'asa00225'
********************************************************
{ Note: The identity string returned by the E3 was:}
[sanei_scsi] OS/2 ' Scanner 1.80SCSI F/WV3.4
CTL5380OŒÅî_'
*******************************************************
{The next "INQUIRY" section shows no sign of trouble. Naturally,
some detailed device properties differ between the 2 models.
The E3 log's Inquiry block follows (If you need the IIG's for
any reason, just ask!) :}
******************************************************
[microtek] attach_scanner: sending INQUIRY
[sanei_scsi] OS/2: ASPI closed
[microtek] id_microtek...
[microtek] parse_inquiry...
[microtek] dump_inquiry...
=== SANE/Microtek backend v0.10.1 ===
========== Scanner Inquiry Block ========mm
06 31 14 01 5b 00 00 00 20 20 20 20 20 20 20 20
53 63 61 6e 6e 65 72 20 20 20 20 20 20 20 20 20
31 2e 38 30 53 43 53 49 20 46 2f 57 56 33 2e 34
20 43 54 4c 35 33 38 30 03 4f 8c c5 02 ee 5f 03
01 03 01 00 00 83 00 01 0e 0e 01 05 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ff
========== Scanner Inquiry Report ==========
===== Scanner ID...
Device Type Code: 0x06
Model Code: 0x5f
Vendor Name: ' ' Model Name: 'Scanner '
Vendor Specific String: 'SCSI F/WV3.4 CTL5380'
Firmware Rev: '1.80'
SCSI F/W version: 3.1 Scanner F/W version: 1.4
Response data format: 0x01
************************************************
{ Details of the Inquiry Report deleted here; if anyone
wants them, let me know by private E-mail
...... the Inquiry Report concludes as follows:}
************************************************
Can Disable Start-of-Scan Recalibration? yes
Internal expanded expansion? no
******
{ Consider this "Point B"}
*************************************************************
{Following completion of the Inquiry Block and Inquiry Report,
the next section is identical for the II-G and the E3:}
*******************************************************************
[microtek] attach_scanner: happy.
[microtek] sane_init: config- {Ctl-Z}[microtek] attach_scanner: {Ctl-Z}
[microtek] attach_scanner: opening {Ctl-Z}
[sanei_init_debug]: Setting debug level of sanei_scsi to 32.
[sanei_scsi] sanei_scsi_open: device name {Ctl-Z} is not valid
[microtek] attach_scanner: open failed
[microtek] sane_open
[microtek] sane_open: find device...
[microtek] attach_scanner: b0t4l0
[microtek] attach_scanner: opening b0t4l0
[sanei_init_debug]: Setting debug level of sanei_scsi to 32.
[sanei_scsi] OS/2: installed adapters 1
*******************************************************************
{And now - for *each* scanner - comes an EXACT repeat of everything
that has happened so far, from "Point A" through "Point B".
Repetition deleted here; but is this supposed to happen?}
************************************************************
{Then at last we get to the substantive differences between scanners.
First, the IIG:}
*************************************************************
[microtek] attach_scanner: happy.
[microtek] sane_open: create scanner...
[microtek] sane_open: initialize scanner dependent stuff...
[microtek] sane_open: precalibration routines disabled.
[microtek] sane_open: init gamma tables...
[microtek] sane_open: init pass-time variables...
[microtek] sane_open: init clever cache...
[microtek] sane_open: initialize options:
[microtek] init_options...
[microtek] init_options: quant yes
[microtek] init_options: done.
[microtek] FLIP ma LID! bind is 1
[microtek] stat is: 4
[microtek] LID be FLIPPED! bind is 1
[microtek] sane_start...
[microtek] sane_get_parameters...
[microtek] sane_get_parameters: non-color
[microtek] sane_get_parameters: res_code = 33 (21)
[microtek] sane_get_parameters: dots_per_mm: 3.937008
[microtek] sane_get_parameters: units_per_mm: 11.811024
[microtek] WIDTHPIX: before exp: 394
[microtek] sane_get_parameters: lines: 394 ppl: 394 bpl: 394
[sanei_init_debug]: Setting debug level of sanei_scsi to 32.
[sanei_scsi] OS/2: installed adapters 1
[sanei_scsi] OS/2: ASPI manager is 'OS2ASPI Dev Mgr AHA-1520/1522 '
[sanei_scsi] OS/2: host adapter is 'AHA-1520/1522 '
[sanei_scsi] OS/2: unique id is ''
[sanei_scsi] open_aspi: open temporary file 'asa00225'
[sanei_scsi] OS/2: adapter#00 'AHA-1520/1522 '
[sanei_scsi] OS/2: id#00 status=82h
[sanei_scsi] OS/2: id#01 status=82h
[sanei_scsi] OS/2: id#02 status=82h
[sanei_scsi] OS/2: id#03 status=82h
[sanei_scsi] OS/2: id#04 status=01h
[sanei_scsi] OS/2: type is 'scanner'
[sanei_scsi] OS/2 'MICROTEKScanMakerIIG 6001.01SCSI FW81193
CLJ1116ŒÅîX'
[sanei_scsi] OS/2: id#05 status=82h
[sanei_scsi] OS/2: id#06 status=82h
[sanei_scsi] open_aspi: close temporary file 'asa00225'
[microtek] .wait_ready 0...
[microtek] .scanning_frame...
[microtek] .scanning_frame: in- 0,0 1181,1181
[microtek] .scanning_frame: out- 0,0 1181,1181
[microtek] .accessory...
[microtek] .download_gamma...
[microtek] .mode_select 0...
[microtek] .mode_select: pap_len: 3505
[microtek] .mode_select_1 0...
[microtek] .wait_ready 0...
[microtek] .start_scan...
*****
{"Point C"}
*****
[microtek] .get_scan_status 0...
[microtek] get_scan_status(6): 0, 394, 393 -> #0
[microtek] > 0 8a 1 89 1 0
[microtek] Scan Param:
[microtek] pix bpl: 394 hdr bpl: 0 ppl: 394
[microtek] undel bytes: 154842 unscan lines: 393 planes: 1
[microtek] dest bpl: 394 dest ppl: 394 aspect: 1.000000
[microtek] sane_get_parameters...
[microtek] sane_read...
[microtek] read_from_scanner...
[microtek] .get_scan_status 0...
[microtek] get_scan_status(6): 0, 394, 393 -> #0
[microtek] > 0 8a 1 89 1 0
[microtek] read_from_scanner: gss busy, linewidth, remaining: 0, 394, 393
[microtek] sane_read: max_scsi: 83, rem: 393, nlines: 83
[microtek] .read_scan_data...
[microtek] sane_read: buffsize: 32702, unscanned: 310
[microtek] pack_into_ring...
[microtek] pack_into_dest...
[microtek] pack_into_dest: rl: 32702 sz: 32702 hc: 0
[microtek] sane_read...
**************************
{ several successful scan-blocks deleted here}
**********************************************************
[microtek] read_from_scanner: gss busy, linewidth, remaining: 0, 394, 61
[microtek] sane_read: max_scsi: 83, rem: 61, nlines: 61
[microtek] .read_scan_data...
[microtek] sane_read: buffsize: 24034, unscanned: 0
[microtek] pack_into_ring...
[microtek] pack_into_dest...
[microtek] pack_into_dest: rl: 24034 sz: 32702 hc: 0
[microtek] sane_read...
[microtek] end_scan...
[microtek] .stop_scan...
[sanei_scsi] sanei_scsi_cmd: command 0x1b failed.
[microtek] end_scan: OY! on stop_scan
[sanei_scsi] OS/2: ASPI closed
[microtek] sane_cancel...
[microtek] end_scan...
[microtek] sane_close...
[microtek] sane_exit...
[microtek] sane_exit: MICROTEK says goodbye.
*************************************************************
{The II-G finishes up with "sanei_scsi_cmd: command 0x1b failed", but
that happens only after periodic (successful) "get_scan_status" commands,
followed by what certainly looks like an orderly shutdown sequence.
Now look at the E3's equivalent run. Compare "Point D", below,
to "Point C" in the II-G log above:}
*************************************************************
[microtek] attach_scanner: happy.
[microtek] sane_open: create scanner...
[microtek] sane_open: initialize scanner dependent stuff...
[microtek] sane_open: init gamma tables...
[microtek] sane_open: init pass-time variables...
[microtek] sane_open: init clever cache...
[microtek] sane_open: initialize options:
[microtek] init_options...
[microtek] init_options: quant yes
[microtek] init_options: done.
[microtek] FLIP ma LID! bind is 1
[microtek] stat is: 4
[microtek] LID be FLIPPED! bind is 1
[microtek] sane_start...
[microtek] sane_get_parameters...
[microtek] sane_get_parameters: non-color
[microtek] sane_get_parameters: res_code = 33 (21)
[microtek] sane_get_parameters: dots_per_mm: 3.937008
[microtek] sane_get_parameters: units_per_mm: 11.811024
[microtek] WIDTHPIX: before exp: 394
[microtek] sane_get_parameters: lines: 394 ppl: 394 bpl: 394
[sanei_init_debug]: Setting debug level of sanei_scsi to 32.
[sanei_scsi] OS/2: installed adapters 1
[sanei_scsi] OS/2: ASPI manager is 'OS2ASPI Dev Mgr AHA-1520/1522 '
[sanei_scsi] OS/2: host adapter is 'AHA-1520/1522 '
[sanei_scsi] OS/2: unique id is ''
[sanei_scsi] open_aspi: open temporary file 'asa00228'
[sanei_scsi] OS/2: adapter#00 'AHA-1520/1522 '
[sanei_scsi] OS/2: id#00 status=82h
[sanei_scsi] OS/2: id#01 status=82h
[sanei_scsi] OS/2: id#02 status=82h
[sanei_scsi] OS/2: id#03 status=82h
[sanei_scsi] OS/2: id#04 status=01h
[sanei_scsi] OS/2: type is 'scanner'
[sanei_scsi] OS/2 ' Scanner 1.80SCSI F/WV3.4
CTL5380OŒÅî_'
[sanei_scsi] OS/2: id#05 status=82h
[sanei_scsi] OS/2: id#06 status=82h
[sanei_scsi] open_aspi: close temporary file 'asa00228'
[microtek] .wait_ready 0...
[microtek] .compare_mode_sense 0...
[microtek] finagle_precal: must precalibrate!
[microtek] do_precalibrate...
[microtek] .wait_ready 0...
[microtek] .scanning_frame...
[microtek] .scanning_frame: in- 0,0 1181,12
[microtek] .scanning_frame: out- 0,0 1181,12
[microtek] .accessory...
[microtek] .mode_select 0...
[microtek] .mode_select: pap_len: 3505
[microtek] .mode_select_1 0...
[microtek] .wait_ready 0...
[microtek] .start_scan...
[microtek] .get_scan_status 0...
[microtek] get_scan_status(6): 0, 394, 4 -> #0
[microtek] > 0 8a 1 4 0 0
[microtek] .stop_scan...
[microtek] .wait_ready 0...
[microtek] do_precalibrate done.
[microtek] .scanning_frame...
[microtek] .scanning_frame: in- 0,0 1181,1181
[microtek] .scanning_frame: out- 0,0 1181,1181
[microtek] .accessory...
[microtek] .download_gamma...
[microtek] .mode_select 0...
[microtek] .mode_select: pap_len: 3505
[microtek] .mode_select_1 0...
[microtek] .save_mode_sense 0...
[microtek] .wait_ready 0...
[microtek] .start_scan...
*****
{"Point D": This is the point at which all E3 action stops, immediately
following one very brief fast move:}
*****
[sanei_scsi] sanei_scsi_cmd: command 0x1b failed.
[microtek] end_scan...
[microtek] .stop_scan...
[sanei_scsi] sanei_scsi_cmd: command 0x1b failed.
[microtek] end_scan: OY! on stop_scan
[sanei_scsi] OS/2: ASPI closed
scanimage: sane_start: Error during device I/O
[microtek] sane_cancel...
[microtek] end_scan...
[microtek] sane_close...
[microtek] sane_exit...
[microtek] sane_exit: MICROTEK says goodbye.
*************************************************************
Yuri added the following comment:
IIG>[microtek] .get_scan_status 0...
IIG>[microtek] get_scan_status(6): 0, 394, 393 -> #0
E3>[microtek] .get_scan_status 0...
E3>[microtek] get_scan_status(6): 0, 394, 4 -> #0
[YD]>Here I see a strange thing: with that inquiry, the last value is the
[YD]>number of lines to be scanned: but on the [II-G] inquiry it is 393,
[YD]>while on the E3 it is only 4.
And there you have it ...
Thanks in advance to all!
Irv Thomae
-- Source code, list archive, and docs: http://www.mostang.com/sane/ To unsubscribe: echo unsubscribe sane-devel | mail majordomo@mostang.com