[sane-devel] scanimage freezes for 3 minutes with Epson Perfection V200 [epkowa]

[emmanuel.michel at wanadoo.fr]

Thanks Olaf for taking the time to help.

OK, now it's even more obscure for me now...

Tonight, I still have the same 3 minutes delay if I do for example:

SANE_DEBUG_DLL=255 scanimage -v -v -v > test.pnm 2> dll-verbose.log

or simply

scanimage > test.pnm

But, if I do:

SANE_DEBUG_SANEI_USB=255 scanimage -v -v -v > test.pnm 2> usb-verbose.log

I have absolutely no delay!

[SANEI_USB]
2012-02-06 22:34:34 scanimage: read 26780688 bytes in total
2012-02-06 22:34:34 Closing device
2012-02-06 22:34:34 [sanei_usb] sanei_usb_write_bulk: trying to write 2 
bytes
2012-02-06 22:34:34 [sanei_usb] 0000: 1E 93 
               ................
2012-02-06 22:34:34 [sanei_usb] sanei_usb_write_bulk: wanted 2 bytes, 
wrote 2 bytes
2012-02-06 22:34:34 [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes
2012-02-06 22:34:34 [sanei_usb] 0000: 06 
               ................
2012-02-06 22:34:34 [sanei_usb] sanei_usb_read_bulk: wanted 1 bytes, got 
1 bytes
2012-02-06 22:34:34 [sanei_usb] sanei_usb_write_bulk: trying to write 1 
bytes
2012-02-06 22:34:34 [sanei_usb] 0000: 00 
               ................
2012-02-06 22:34:34 [sanei_usb] sanei_usb_write_bulk: wanted 1 bytes, 
wrote 1 bytes
2012-02-06 22:34:34 [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes
2012-02-06 22:34:34 [sanei_usb] 0000: 06 
               ........$
2012-02-06 22:34:34 [sanei_usb] sanei_usb_read_bulk: wanted 1 bytes, got 
1 bytes
2012-02-06 22:34:34 [sanei_usb] sanei_usb_close: closing device 0
2012-02-06 22:34:34 Calling sane_exit
2012-02-06 22:34:34 scanimage: finished

Regarding your SANEI_USB_KEEP_USBLP suggestion, I see no difference in 
the log. Can you please confirm the use of this variable ? I presume you 
want me to use the following command:

SANE_DEBUG_SANEI_USB=255 SANEI_USB_KEEP_USBLP=no scanimage -v -v -v > 
test.pnm 2> usb-verbose.log

Thanks.

Emmanuel


Le 06/02/2012 04:53, Olaf Meeuwissen a écrit :
> "emmanuel.michel at wanadoo.fr"<emmanuel.michel at wanadoo.fr>  writes:
>
>> The setup:
>> Scanner EPSON Prefection V200
>> OS Ubuntu Server 64 bits 10.04.3
>>
>> libsane 1.0.20-13ubuntu2
>> sane-utils 1.0.20-13ubuntu2
>> iscan 2.28.1-3.ltdl7
>> iscan-data 1.14.0-1
>> iscan-plugin-gt-f670 2.1.2-1
>>
>> The problem:
>> Everytime I scan a document with scanimage I have to wait _exactly_ 3
>> minutes before it returns to the command line. Below are the end of
>> the debug logs from dll and epkowa:
>>
>> [DLL]
>> 2012-02-05 20:48:31 scanimage: read 26780688 bytes in total
>> 2012-02-05 20:48:31 [dll] sane_cancel(handle=0x1088da0)
>> 2012-02-05 20:48:31 Closing device
>> 2012-02-05 20:48:31 [dll] sane_close(handle=0x1088da0)
>> 2012-02-05 20:51:31 Calling sane_exit
>> 2012-02-05 20:51:31 [dll] sane_exit: exiting
>> 2012-02-05 20:51:31 [dll] sane_exit: calling backend `epkowa's exit function
>> 2012-02-05 20:51:31 [dll] sane_exit: finished
>> 2012-02-05 20:51:31 scanimage: finished
>>
>> [EPKOWA]
>> 2012-02-05 20:58:42 scanimage: read 26780688 bytes in total
>> 2012-02-05 20:58:42 epkowa.c:5955: [epkowa]{C} sane_epkowa_cancel
>> 2012-02-05 20:58:42 device.c:536: [epkowa]{C} dev_unlock
>> 2012-02-05 20:58:42 Closing device
>> 2012-02-05 20:58:42 epkowa.c:2554: [epkowa]{C} sane_epkowa_close
>> 2012-02-05 20:58:42 device.c:242: [epkowa]{C} dev_close (fd = 0)
>> 2012-02-05 21:01:42 Calling sane_exit
>> 2012-02-05 21:01:42 backend.c:251: [epkowa]{C} sane_epkowa_exit ()
>> 2012-02-05 21:01:42 dip-obj.c:152: [epkowa]{C} dip_exit (0x1fe46b0)
>> 2012-02-05 21:01:42 cfg-obj.c:468: [epkowa]{C} cfg_has (0x1fdf630, 4)
>> 2012-02-05 21:01:42 cfg-obj.c:468: [epkowa]{C} cfg_has (0x1fdf630, 3)
>> 2012-02-05 21:01:42 cfg-obj.c:468: [epkowa]{C} cfg_has (0x1fdf630, 2)
>> 2012-02-05 21:01:42 cfg-obj.c:468: [epkowa]{C} cfg_has (0x1fdf630, 1)
>> 2012-02-05 21:01:42 cfg-obj.c:411: [epkowa]{C} cfg_exit (0x1fdf630)
>> 2012-02-05 21:01:42 model-info.c:209: [epkowa]{C} model_info_cache_exit (0x1fdf$
>> 2012-02-05 21:01:42 scanimage: finished
>>
>> As you can see, I always have this 3 minutes delay just after
>> sane_close. I would be glad if someone could help me to understand
>> what this temporal hole is about. Thanks in advance.
>
> This is caused by one or more of:
>   - the interpreter taking its time to clean up and leave the device in a
>     consistent state
>   - the SANE USB layer taking its time to reattach the usblp module
>
> To identify the culprit could you please provide the relevant part of
> the SANEI_USB log, with and without the SANEI_USB_KEEP_USBLP variable
> set?  This environment variable can be set to completely disable the
> (iscan specific) usblp module tweaks in the backend.
>
> Hope this helps,