[sane-devel] scanimage freezes for 3 minutes with Epson Perfection V200 [epkowa]
Wilhelm I promise I'll post to confirm when it'll work. Problem is I'm a Linux newbie so I'm slow as I discover a lot of things :-). scanbd is the first program I compile (stop laughing please). For now I can confirm I patched scanbd to add a scanbuttond backend specific to the Espon v200 (because as far as I know epkowa backend won't allow me to manage the buttons of this scanner), I run it using xinetd, the 4 functions are discovered so I'll make my scripts. After that, I'll try to make sure saned is ok and better understand some parts of your doc to be sure everything is OK. Such as for example the part "If scanbd is running on a desktop machine..." which is obscure to me ;-) I'm glad to have scanbd as it seems it will end the fight between saned and scanbuttond. Thanks for it ! Bests, Emmanuel Le 09/02/2012 12:33, Wilhelm a ?crit : >> In the meantime I'll return to scanbd as I'm about to succeed having all >> the 4 buttons working now :-) > > Are there any issues regarding scanbd? > > Regards, > > Wilhelm
[sane-devel] scanimage freezes for 3 minutes with Epson Perfection V200 [epkowa]
Am 09.02.2012 10:13, schrieb emmanuel.michel at wanadoo.fr: > Thanks a lot for your investigations Olaf ! At least, having an > explanation/confirmation is a step towards a solution. Now eagerly > waiting for a fix ;-) > > In the meantime I'll return to scanbd as I'm about to succeed having all > the 4 buttons working now :-) Are there any issues regarding scanbd? Regards, Wilhelm > > Bests, > > Emmanuel > > > Le 09/02/2012 02:22, Olaf Meeuwissen a ?crit : >> "emmanuel.michel at wanadoo.fr" writes: >> >>> After further investigations, here is what I found so far: >>> >>> SANE_DEBUG_SANEI_USB=11 scanimage -v -v -v --format=tiff> test.tiff 2> >>> usb-verbose-11.log >> >> SANE_DEBUG_SANEI_USB> 10 turns on the hexdump of the USB packet >> payloads and therefore changes the timing of when things happen. >> More precisely, it changes the speed with which events proceed. >> >>> gives no delay at all but I can hear the carriage hangs/stops few >>> times (each time being a millisecond or so) during the scan. >>> >>> [SANE_DEBBUG_SANEI_USB=11] >>> 2012-02-07 12:25:06 scanimage: read 26780688 bytes in total >>> 2012-02-07 12:25:06 Closing device >>> 2012-02-07 12:25:06 [sanei_usb] sanei_usb_write_bulk: trying to write >>> 2 bytes >>> 2012-02-07 12:25:06 [sanei_usb] : 1E 93 >>> 2012-02-07 12:25:06 [sanei_usb] sanei_usb_write_bulk: wanted 2 bytes, >>> wrote 2 bytes >>> 2012-02-07 12:25:06 [sanei_usb] sanei_usb_read_bulk: trying to read 1 >>> bytes >>> 2012-02-07 12:25:06 [sanei_usb] : 06 >>> 2012-02-07 12:25:06 [sanei_usb] sanei_usb_read_bulk: wanted 1 bytes, >>> got 1 bytes >>> 2012-02-07 12:25:06 [sanei_usb] sanei_usb_write_bulk: trying to write >>> 1 bytes >>> 2012-02-07 12:25:06 [sanei_usb] : 00 >>> 2012-02-07 12:25:06 [sanei_usb] sanei_usb_write_bulk: wanted 1 bytes, >>> wrote 1 bytes >>> 2012-02-07 12:25:06 [sanei_usb] sanei_usb_read_bulk: trying to read 1 >>> bytes >>> 2012-02-07 12:25:06 [sanei_usb] : 06 >>> 2012-02-07 12:25:06 [sanei_usb] sanei_usb_read_bulk: wanted 1 bytes, >>> got 1 bytes >>> 2012-02-07 12:25:06 [sanei_usb] sanei_usb_close: closing device 0 >>> 2012-02-07 12:25:06 Calling sane_exit >>> 2012-02-07 12:25:06 scanimage: finished >>> >>> SANE_DEBUG_SANEI_USB=10 scanimage -v -v -v --format=tiff> test.tiff 2> >>> usb-verbose-10.log >>> >>> gives the bothering 3 minutes delay but the carriage movement during >>> the scanning is perfectly smooth. >>> >>> [SANE_DEBUG_SANEI_USB=10] >>> 2012-02-07 12:29:48 scanimage: read 26780688 bytes in total >>> 2012-02-07 12:29:48 Closing device >>> 2012-02-07 12:29:48 [sanei_usb] sanei_usb_write_bulk: trying to write >>> 2 bytes >>> 2012-02-07 12:29:48 [sanei_usb] sanei_usb_write_bulk: wanted 2 bytes, >>> wrote 2 bytes >>> 2012-02-07 12:29:48 [sanei_usb] sanei_usb_read_bulk: trying to read 1 >>> bytes >>> 2012-02-07 12:30:18 [sanei_usb] sanei_usb_read_bulk: trying to read 1 >>> bytes >>> 2012-02-07 12:30:48 [sanei_usb] sanei_usb_read_bulk: trying to read 1 >>> bytes >>> 2012-02-07 12:31:18 [sanei_usb] sanei_usb_read_bulk: read failed: >>> Resource temporarily unavailable >> >> OK, we've got a read failure here. >> >>> 2012-02-07 12:31:18 [sanei_usb] sanei_usb_write_bulk: trying to write >>> 1 bytes >>> 2012-02-07 12:31:18 [sanei_usb] sanei_usb_write_bulk: wanted 1 bytes, >>> wrote 1 bytes >> >> And a successful write here. >> >>> 2012-02-07 12:31:18 [sanei_usb] sanei_usb_read_bulk: trying to read 1 >>> bytes >>> 2012-02-07 12:31:48 [sanei_usb] sanei_usb_read_bulk: trying to read 1 >>> bytes >>> 2012-02-07 12:32:18 [sanei_usb] sanei_usb_read_bulk: trying to read 1 >>> bytes >>> 2012-02-07 12:32:48 [sanei_usb] sanei_usb_read_bulk: read failed: >>> Resource temporarily unavailable >> >> And another read failure here. >> >>> 2012-02-07 12:32:48 [sanei_usb] sanei_usb_close: closing device 0 >>> 2012-02-07 12:32:48 Calling sane_exit >>> 2012-02-07 12:32:48 scanimage: finished >> >> Both read failures are logged after three attempts to read a byte, each >> 30 seconds apart. That's 1.5 minutes for the first read failure and >> another 1.5 minutes for the next. There you go, three minutes exactly. >> Note that the USB timeout is hard-coded to 30 seconds and the sanei_usb >> code (as used by iscan) is responsible for the three time repeat. >> >>> I also noted that after a "3 minutes delay", I can't turn off the >>> scanner (have to unplug it) so it seems something really bother it. As >>> soon as I re-do a scan without the "3 minutes delay" (ie using >>> SANE_DEBUG_SANEI_USB=11), then I can turn it off straight away without >>> any problem. >> >> I trudged through the interpreter code and found something interesting >> there that is *probably* the cause of this. I haven't done any testing >> so far but it appear that the first read failure is not handled the way >> it should (or no attempts are made to prevent it in the first place). >> >> FTR, it looks like the interpreter is running at
[sane-devel] scanimage freezes for 3 minutes with Epson Perfection V200 [epkowa]
"emmanuel.michel at wanadoo.fr" writes: > After further investigations, here is what I found so far: > > SANE_DEBUG_SANEI_USB=11 scanimage -v -v -v --format=tiff> test.tiff 2> > usb-verbose-11.log SANE_DEBUG_SANEI_USB > 10 turns on the hexdump of the USB packet payloads and therefore changes the timing of when things happen. More precisely, it changes the speed with which events proceed. > gives no delay at all but I can hear the carriage hangs/stops few > times (each time being a millisecond or so) during the scan. > > [SANE_DEBBUG_SANEI_USB=11] > 2012-02-07 12:25:06 scanimage: read 26780688 bytes in total > 2012-02-07 12:25:06 Closing device > 2012-02-07 12:25:06 [sanei_usb] sanei_usb_write_bulk: trying to write > 2 bytes > 2012-02-07 12:25:06 [sanei_usb] : 1E 93 > 2012-02-07 12:25:06 [sanei_usb] sanei_usb_write_bulk: wanted 2 bytes, > wrote 2 bytes > 2012-02-07 12:25:06 [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes > 2012-02-07 12:25:06 [sanei_usb] : 06 > 2012-02-07 12:25:06 [sanei_usb] sanei_usb_read_bulk: wanted 1 bytes, > got 1 bytes > 2012-02-07 12:25:06 [sanei_usb] sanei_usb_write_bulk: trying to write > 1 bytes > 2012-02-07 12:25:06 [sanei_usb] : 00 > 2012-02-07 12:25:06 [sanei_usb] sanei_usb_write_bulk: wanted 1 bytes, > wrote 1 bytes > 2012-02-07 12:25:06 [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes > 2012-02-07 12:25:06 [sanei_usb] : 06 > 2012-02-07 12:25:06 [sanei_usb] sanei_usb_read_bulk: wanted 1 bytes, > got 1 bytes > 2012-02-07 12:25:06 [sanei_usb] sanei_usb_close: closing device 0 > 2012-02-07 12:25:06 Calling sane_exit > 2012-02-07 12:25:06 scanimage: finished > > SANE_DEBUG_SANEI_USB=10 scanimage -v -v -v --format=tiff> test.tiff 2> > usb-verbose-10.log > > gives the bothering 3 minutes delay but the carriage movement during > the scanning is perfectly smooth. > > [SANE_DEBUG_SANEI_USB=10] > 2012-02-07 12:29:48 scanimage: read 26780688 bytes in total > 2012-02-07 12:29:48 Closing device > 2012-02-07 12:29:48 [sanei_usb] sanei_usb_write_bulk: trying to write > 2 bytes > 2012-02-07 12:29:48 [sanei_usb] sanei_usb_write_bulk: wanted 2 bytes, > wrote 2 bytes > 2012-02-07 12:29:48 [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes > 2012-02-07 12:30:18 [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes > 2012-02-07 12:30:48 [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes > 2012-02-07 12:31:18 [sanei_usb] sanei_usb_read_bulk: read failed: > Resource temporarily unavailable OK, we've got a read failure here. > 2012-02-07 12:31:18 [sanei_usb] sanei_usb_write_bulk: trying to write > 1 bytes > 2012-02-07 12:31:18 [sanei_usb] sanei_usb_write_bulk: wanted 1 bytes, > wrote 1 bytes And a successful write here. > 2012-02-07 12:31:18 [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes > 2012-02-07 12:31:48 [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes > 2012-02-07 12:32:18 [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes > 2012-02-07 12:32:48 [sanei_usb] sanei_usb_read_bulk: read failed: > Resource temporarily unavailable And another read failure here. > 2012-02-07 12:32:48 [sanei_usb] sanei_usb_close: closing device 0 > 2012-02-07 12:32:48 Calling sane_exit > 2012-02-07 12:32:48 scanimage: finished Both read failures are logged after three attempts to read a byte, each 30 seconds apart. That's 1.5 minutes for the first read failure and another 1.5 minutes for the next. There you go, three minutes exactly. Note that the USB timeout is hard-coded to 30 seconds and the sanei_usb code (as used by iscan) is responsible for the three time repeat. > I also noted that after a "3 minutes delay", I can't turn off the > scanner (have to unplug it) so it seems something really bother it. As > soon as I re-do a scan without the "3 minutes delay" (ie using > SANE_DEBUG_SANEI_USB=11), then I can turn it off straight away without > any problem. I trudged through the interpreter code and found something interesting there that is *probably* the cause of this. I haven't done any testing so far but it appear that the first read failure is not handled the way it should (or no attempts are made to prevent it in the first place). FTR, it looks like the interpreter is running at a faster speed than the device can handle. > I continue my tests... Don't bother. It's a bug in the interpreter (thanks BTW for reporting it) and unless a fixed interpreter plugin is released there's nothing you can do (that's non-free software for you!). I'll file a bug report (internally) here and see if something can be done about it. > Bests, Sorry this doesn't help. For the time being, I'd suggest working around by scanning with the USB debugging turned on at levels > 10 and diverted to /dev/null. Yuck! > Emmanuel > > > Le 07/02/2012 00:55, Olaf Meeuwissen a ?crit : >> "emmanuel.michel at wanadoo.fr" writes: >> >>> Thanks O
[sane-devel] scanimage freezes for 3 minutes with Epson Perfection V200 [epkowa]
Thanks a lot for your investigations Olaf ! At least, having an explanation/confirmation is a step towards a solution. Now eagerly waiting for a fix ;-) In the meantime I'll return to scanbd as I'm about to succeed having all the 4 buttons working now :-) Bests, Emmanuel Le 09/02/2012 02:22, Olaf Meeuwissen a ?crit : > "emmanuel.michel at wanadoo.fr" writes: > >> After further investigations, here is what I found so far: >> >> SANE_DEBUG_SANEI_USB=11 scanimage -v -v -v --format=tiff> test.tiff 2> >> usb-verbose-11.log > > SANE_DEBUG_SANEI_USB> 10 turns on the hexdump of the USB packet > payloads and therefore changes the timing of when things happen. > More precisely, it changes the speed with which events proceed. > >> gives no delay at all but I can hear the carriage hangs/stops few >> times (each time being a millisecond or so) during the scan. >> >> [SANE_DEBBUG_SANEI_USB=11] >> 2012-02-07 12:25:06 scanimage: read 26780688 bytes in total >> 2012-02-07 12:25:06 Closing device >> 2012-02-07 12:25:06 [sanei_usb] sanei_usb_write_bulk: trying to write >> 2 bytes >> 2012-02-07 12:25:06 [sanei_usb] : 1E 93 >> 2012-02-07 12:25:06 [sanei_usb] sanei_usb_write_bulk: wanted 2 bytes, >> wrote 2 bytes >> 2012-02-07 12:25:06 [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes >> 2012-02-07 12:25:06 [sanei_usb] : 06 >> 2012-02-07 12:25:06 [sanei_usb] sanei_usb_read_bulk: wanted 1 bytes, >> got 1 bytes >> 2012-02-07 12:25:06 [sanei_usb] sanei_usb_write_bulk: trying to write >> 1 bytes >> 2012-02-07 12:25:06 [sanei_usb] : 00 >> 2012-02-07 12:25:06 [sanei_usb] sanei_usb_write_bulk: wanted 1 bytes, >> wrote 1 bytes >> 2012-02-07 12:25:06 [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes >> 2012-02-07 12:25:06 [sanei_usb] : 06 >> 2012-02-07 12:25:06 [sanei_usb] sanei_usb_read_bulk: wanted 1 bytes, >> got 1 bytes >> 2012-02-07 12:25:06 [sanei_usb] sanei_usb_close: closing device 0 >> 2012-02-07 12:25:06 Calling sane_exit >> 2012-02-07 12:25:06 scanimage: finished >> >> SANE_DEBUG_SANEI_USB=10 scanimage -v -v -v --format=tiff> test.tiff 2> >> usb-verbose-10.log >> >> gives the bothering 3 minutes delay but the carriage movement during >> the scanning is perfectly smooth. >> >> [SANE_DEBUG_SANEI_USB=10] >> 2012-02-07 12:29:48 scanimage: read 26780688 bytes in total >> 2012-02-07 12:29:48 Closing device >> 2012-02-07 12:29:48 [sanei_usb] sanei_usb_write_bulk: trying to write >> 2 bytes >> 2012-02-07 12:29:48 [sanei_usb] sanei_usb_write_bulk: wanted 2 bytes, >> wrote 2 bytes >> 2012-02-07 12:29:48 [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes >> 2012-02-07 12:30:18 [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes >> 2012-02-07 12:30:48 [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes >> 2012-02-07 12:31:18 [sanei_usb] sanei_usb_read_bulk: read failed: >> Resource temporarily unavailable > > OK, we've got a read failure here. > >> 2012-02-07 12:31:18 [sanei_usb] sanei_usb_write_bulk: trying to write >> 1 bytes >> 2012-02-07 12:31:18 [sanei_usb] sanei_usb_write_bulk: wanted 1 bytes, >> wrote 1 bytes > > And a successful write here. > >> 2012-02-07 12:31:18 [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes >> 2012-02-07 12:31:48 [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes >> 2012-02-07 12:32:18 [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes >> 2012-02-07 12:32:48 [sanei_usb] sanei_usb_read_bulk: read failed: >> Resource temporarily unavailable > > And another read failure here. > >> 2012-02-07 12:32:48 [sanei_usb] sanei_usb_close: closing device 0 >> 2012-02-07 12:32:48 Calling sane_exit >> 2012-02-07 12:32:48 scanimage: finished > > Both read failures are logged after three attempts to read a byte, each > 30 seconds apart. That's 1.5 minutes for the first read failure and > another 1.5 minutes for the next. There you go, three minutes exactly. > Note that the USB timeout is hard-coded to 30 seconds and the sanei_usb > code (as used by iscan) is responsible for the three time repeat. > >> I also noted that after a "3 minutes delay", I can't turn off the >> scanner (have to unplug it) so it seems something really bother it. As >> soon as I re-do a scan without the "3 minutes delay" (ie using >> SANE_DEBUG_SANEI_USB=11), then I can turn it off straight away without >> any problem. > > I trudged through the interpreter code and found something interesting > there that is *probably* the cause of this. I haven't done any testing > so far but it appear that the first read failure is not handled the way > it should (or no attempts are made to prevent it in the first place). > > FTR, it looks like the interpreter is running at a faster speed than the > device can handle. > >> I continue my tests... > > Don't bother. It's a bug in the interpreter (thanks BTW for reporting > it) and unless a fixed interpreter plugin is released
[sane-devel] scanimage freezes for 3 minutes with Epson Perfection V200 [epkowa]
OK. After further investigations, here is what I found so far: SANE_DEBUG_SANEI_USB=11 scanimage -v -v -v --format=tiff> test.tiff 2> usb-verbose-11.log gives no delay at all but I can hear the carriage hangs/stops few times (each time being a millisecond or so) during the scan. [SANE_DEBBUG_SANEI_USB=11] 2012-02-07 12:25:06 scanimage: read 26780688 bytes in total 2012-02-07 12:25:06 Closing device 2012-02-07 12:25:06 [sanei_usb] sanei_usb_write_bulk: trying to write 2 bytes 2012-02-07 12:25:06 [sanei_usb] : 1E 93 2012-02-07 12:25:06 [sanei_usb] sanei_usb_write_bulk: wanted 2 bytes, wrote 2 bytes 2012-02-07 12:25:06 [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes 2012-02-07 12:25:06 [sanei_usb] : 06 2012-02-07 12:25:06 [sanei_usb] sanei_usb_read_bulk: wanted 1 bytes, got 1 bytes 2012-02-07 12:25:06 [sanei_usb] sanei_usb_write_bulk: trying to write 1 bytes 2012-02-07 12:25:06 [sanei_usb] : 00 2012-02-07 12:25:06 [sanei_usb] sanei_usb_write_bulk: wanted 1 bytes, wrote 1 bytes 2012-02-07 12:25:06 [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes 2012-02-07 12:25:06 [sanei_usb] : 06 2012-02-07 12:25:06 [sanei_usb] sanei_usb_read_bulk: wanted 1 bytes, got 1 bytes 2012-02-07 12:25:06 [sanei_usb] sanei_usb_close: closing device 0 2012-02-07 12:25:06 Calling sane_exit 2012-02-07 12:25:06 scanimage: finished SANE_DEBUG_SANEI_USB=10 scanimage -v -v -v --format=tiff> test.tiff 2> usb-verbose-10.log gives the bothering 3 minutes delay but the carriage movement during the scanning is perfectly smooth. [SANE_DEBUG_SANEI_USB=10] 2012-02-07 12:29:48 scanimage: read 26780688 bytes in total 2012-02-07 12:29:48 Closing device 2012-02-07 12:29:48 [sanei_usb] sanei_usb_write_bulk: trying to write 2 bytes 2012-02-07 12:29:48 [sanei_usb] sanei_usb_write_bulk: wanted 2 bytes, wrote 2 bytes 2012-02-07 12:29:48 [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes 2012-02-07 12:30:18 [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes 2012-02-07 12:30:48 [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes 2012-02-07 12:31:18 [sanei_usb] sanei_usb_read_bulk: read failed: Resource temporarily unavailable 2012-02-07 12:31:18 [sanei_usb] sanei_usb_write_bulk: trying to write 1 bytes 2012-02-07 12:31:18 [sanei_usb] sanei_usb_write_bulk: wanted 1 bytes, wrote 1 bytes 2012-02-07 12:31:18 [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes 2012-02-07 12:31:48 [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes 2012-02-07 12:32:18 [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes 2012-02-07 12:32:48 [sanei_usb] sanei_usb_read_bulk: read failed: Resource temporarily unavailable 2012-02-07 12:32:48 [sanei_usb] sanei_usb_close: closing device 0 2012-02-07 12:32:48 Calling sane_exit 2012-02-07 12:32:48 scanimage: finished I also noted that after a "3 minutes delay", I can't turn off the scanner (have to unplug it) so it seems something really bother it. As soon as I re-do a scan without the "3 minutes delay" (ie using SANE_DEBUG_SANEI_USB=11), then I can turn it off straight away without any problem. I continue my tests... Bests, Emmanuel Le 07/02/2012 00:55, Olaf Meeuwissen a ?crit : > "emmanuel.michel at wanadoo.fr" writes: > >> 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! > > Weird indeed. Anyone have any idea why this might happen? > > FYI, the epkowa backend uses sanei_usb_*_bulk() API to read and write > througout. The interpreter gets two callbacks that wrap this API. Do > note though that the backend uses a copy of sanei_usb.c from way back > (sane-backends 1.0.12, but we're updating as I write ;-). > >> [SANEI_USB] >> 2012-02-06 22:34:34 scanimage: read 26780688 bytes in total > > Looks like you did acquire an image so the backend is going through its > usual hoops. For a moment, I considered that scanimage might have just > exited rightaway without doing anything. > >> 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] : 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] : 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 byt
[sane-devel] scanimage freezes for 3 minutes with Epson Perfection V200 [epkowa]
"emmanuel.michel at wanadoo.fr" writes:
> 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!
Weird indeed. Anyone have any idea why this might happen?
FYI, the epkowa backend uses sanei_usb_*_bulk() API to read and write
througout. The interpreter gets two callbacks that wrap this API. Do
note though that the backend uses a copy of sanei_usb.c from way back
(sane-backends 1.0.12, but we're updating as I write ;-).
> [SANEI_USB]
> 2012-02-06 22:34:34 scanimage: read 26780688 bytes in total
Looks like you did acquire an image so the backend is going through its
usual hoops. For a moment, I considered that scanimage might have just
exited rightaway without doing anything.
> 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] : 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] : 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] : 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] : 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
Yes, that usage is fine. The reason you see no difference is probably
because the usblp kernel module is blacklisted (by CUPS, IIRC). When
that's the case, the epkowa backend doesn't have to do anything special
to begin with.
The backend detaches the usblp module before scanning and re-attaches
it when done. This is an ugly hack to get a number of all-in-ones to
behave again with 2.6.13 kernels or later. I thought that maybe that
re-attaching was causing the 3 minute wait. Guess not.
> Le 06/02/2012 04:53, Olaf Meeuwissen a ?crit :
>> "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_in
[sane-devel] scanimage freezes for 3 minutes with Epson Perfection V200 [epkowa]
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] : 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] : 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] : 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] : 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" 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,
[sane-devel] scanimage freezes for 3 minutes with Epson Perfection V200 [epkowa]
"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,
--
Olaf Meeuwissen, LPIC-2 FLOSS Engineer -- AVASYS CORPORATION
FSF Associate Member #1962 Help support software freedom
http://www.fsf.org/jf?referrer=1962
[sane-devel] scanimage freezes for 3 minutes with Epson Perfection V200 [epkowa]
Hello,
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.
Bests,
Emmanuel MICHEL
