sane_open(), sane_read() and sane_close() are very slow on HP Laser MFP 135WR

[vklachkov]

I was experimenting with the SANE API and noticed that sane_open(), first call of sane_read() and sane_close() on scanner HP Laser MFP 135WR take a long time.

sane_open() call takes ~1 second. First sane_read() call takes ~10 seconds. sane_close() takes ~6 seconds.

Time doesn't change whether the MFP is in power save mode or not.

To check, I woke up the scanner from power save mode and ran scanimage:

$ time scanimage --device-name="airscan:e0:HP_Laser_MFP_135wr" --format=jpeg --output="output.jpeg"
scanimage --device-name="airscan:e0:HP_Laser_MFP_135wr" --format=jpeg   0.12s user 0.02s system 0% cpu 17.545 total

For example, the same command, but using v4l backend:

$ time scanimage --device-name="v4l:/dev/video0" --mode color --format=jpeg --output="output.jpeg"                                                                      
scanimage --device-name="v4l:/dev/video0" --mode color --format=jpeg   0.04s user 0.01s system 4% cpu 0.990 total

sane-airscan config

``` $ sudo cat /etc/sane.d/airscan.conf ``` ```config [devices] "HP_Laser_MFP_135wr" = https://192.168.1.121:443/eSCL [options] discovery = disable [debug] #trace = ~/airscan/trace #enable = true ```

If necessary, I can provide any logs and help with debugging.

[alexpevzner]

Hi @zgdump,

first of all, I need to see protocol traces (and the same for #332 too). To obtain them, in the /etc/sane.d/airscan.conf uncomment the following lines:

[debug]
trace = ~/airscan/trace

The ~/airscan/trace will be created automatically and traces will be written there. For now I only need *.log files, but not *.tar.

P.S. Are you just a regular user, or you work for some distro?

[vklachkov]

@alexpevzner

I'm regular user.

Command:

$ scanimage -v --device-name="airscan:e0:HP_Laser_MFP_135wr" --mode color --format=jpeg --output="output.jpeg"

Logs:

scanimage-HP_Laser_MFP_135wr.log

scanimage-zeroconf.log

[vklachkov]

I also tried using HTTP instead of HTTPS, replacing https://192.168.1.121:443/eSCL with http://192.168.1.121/eSCL, but although this speed up scan by 2 secs, it didn't fix the problem.

[vklachkov]

Logs for https://github.com/alexpevzner/sane-airscan/issues/332:

mfp3000bot-HP_Laser_MFP_135wr.log

mfp3000bot-zeroconf.log

[alexpevzner]

Hi @zgdump

sane_open in your log takes few milliseconds. Typically it is fast, but if it is called very early, it may block waiting for device discovery completion, which may take, depending on circumstances, up to 5 seconds (starting from the driver initialization), but in most cases takes less time. Please note, discovery starts as soon as driver is loaded, so on many cases at the time sane_open is called, discovery already completed.

sane_read(), in blocking mode, will wait until scanning is finished and the whole image is downloaded. Depending on device and scan resolution it may take a lot of time. Please note, there is a non-blocking mode of the sane_read(), at this mode it returns immediately if image is not ready yet.

sane_close() will wait until completion of currently executing job (it will attempt to cancel job in progress, or just wait until completion of some cleanup steps, that performed after image downloading completion, and it really may take seconds, depending on device). Without these cleanup steps we may leave device in unstable state, so the next scan attempt will fail. In your case it really took ~6 seconds for device to respons.

So here I don't see anything to go wrong, though device is really a bit slow sometimes.

[vklachkov]

@alexpevzner

Thank you very much for your detailed answer! Now I understand why scan tooks so many time.

Have you looked logs for the https://github.com/alexpevzner/sane-airscan/issues/332? Is this also a problem with the scanner?