SimulPiscator / AirSane

Publish SANE scanners to MacOS, Android, and Windows via Apple AirScan.
GNU General Public License v3.0
243 stars 26 forks source link

airsane can't scan while scanimage works #82

Closed ilya-fedin closed 2 years ago

ilya-fedin commented 2 years ago

I have a weird issue that airsane detects the scanner, but can't scan (tried with mopria & web interface, both failing) while scanimage started as the same user works just fine.

Here's the log running in normal mode:

окт 15 23:55:29 rpi4 airsaned[22862]: io/hpmud/musb.c 427: Found interface conf=0, iface=0, altset=1, index=1
окт 15 23:55:29 rpi4 airsaned[22862]: io/hpmud/musb.c 389: Active kernel driver on interface=0 ret=0
окт 15 23:55:29 rpi4 airsaned[22862]: io/hpmud/musb.c 535: claimed 7/1/2 interface
окт 15 23:55:29 rpi4 airsaned[22862]: io/hpmud/musb.c 780: read actual device_id successfully fd=1 len=157
окт 15 23:55:29 rpi4 airsaned[22862]: io/hpmud/musb.c 561: released 7/1/2 interface
окт 15 23:55:29 rpi4 airsaned[22862]: io/hpmud/musb.c 427: Found interface conf=0, iface=0, altset=1, index=1
окт 15 23:55:29 rpi4 airsaned[22862]: io/hpmud/musb.c 389: Active kernel driver on interface=0 ret=0
окт 15 23:55:29 rpi4 airsaned[22862]: io/hpmud/musb.c 535: claimed 7/1/2 interface
окт 15 23:55:29 rpi4 airsaned[22862]: io/hpmud/musb.c 780: read actual device_id successfully fd=1 len=157
окт 15 23:55:29 rpi4 airsaned[22862]: io/hpmud/musb.c 561: released 7/1/2 interface
окт 15 23:55:29 rpi4 airsaned[22862]: io/hpmud/musb.c 960: new HP-MESSAGE channel=1 clientCnt=1 channelCnt=1
окт 15 23:55:29 rpi4 airsaned[22862]: io/hpmud/musb.c 427: Found interface conf=0, iface=0, altset=0, index=2
окт 15 23:55:29 rpi4 airsaned[22862]: io/hpmud/musb.c 389: Active kernel driver on interface=0 ret=0
окт 15 23:55:29 rpi4 airsaned[22862]: io/hpmud/musb.c 535: claimed 7/1/3 interface
окт 15 23:55:29 rpi4 airsaned[22862]: io/hpmud/musb.c 561: released 7/1/3 interface
окт 15 23:55:30 rpi4 airsaned[22862]: io/hpmud/musb.c 975: removed HP-MESSAGE channel=1 clientCnt=0 channelCnt=0
окт 15 23:55:37 rpi4 airsaned[22862]: io/hpmud/musb.c 427: Found interface conf=0, iface=0, altset=1, index=1
окт 15 23:55:37 rpi4 airsaned[22862]: io/hpmud/musb.c 389: Active kernel driver on interface=0 ret=0
окт 15 23:55:37 rpi4 airsaned[22862]: io/hpmud/musb.c 535: claimed 7/1/2 interface
окт 15 23:55:37 rpi4 airsaned[22862]: io/hpmud/musb.c 780: read actual device_id successfully fd=1 len=157
окт 15 23:55:37 rpi4 airsaned[22862]: io/hpmud/musb.c 561: released 7/1/2 interface
окт 15 23:55:37 rpi4 airsaned[22862]: io/hpmud/musb.c 427: Found interface conf=0, iface=0, altset=1, index=1
окт 15 23:55:37 rpi4 airsaned[22862]: io/hpmud/musb.c 389: Active kernel driver on interface=0 ret=0
окт 15 23:55:37 rpi4 airsaned[22862]: io/hpmud/musb.c 535: claimed 7/1/2 interface
окт 15 23:55:37 rpi4 airsaned[22862]: io/hpmud/musb.c 780: read actual device_id successfully fd=1 len=157
окт 15 23:55:37 rpi4 airsaned[22862]: io/hpmud/musb.c 561: released 7/1/2 interface
окт 15 23:55:37 rpi4 airsaned[22862]: io/hpmud/musb.c 960: new HP-MESSAGE channel=1 clientCnt=1 channelCnt=1
окт 15 23:55:37 rpi4 airsaned[22862]: io/hpmud/musb.c 427: Found interface conf=0, iface=0, altset=0, index=2
окт 15 23:55:37 rpi4 airsaned[22862]: io/hpmud/musb.c 389: Active kernel driver on interface=0 ret=0
окт 15 23:55:37 rpi4 airsaned[22862]: io/hpmud/musb.c 535: claimed 7/1/3 interface
окт 15 23:55:37 rpi4 airsaned[22862]: io/hpmud/musb.c 561: released 7/1/3 interface
окт 15 23:55:38 rpi4 airsaned[22862]: io/hpmud/musb.c 975: removed HP-MESSAGE channel=1 clientCnt=0 channelCnt=0
окт 15 23:55:38 rpi4 airsaned[22862]: io/hpmud/musb.c 960: new HP-MESSAGE channel=1 clientCnt=1 channelCnt=1
окт 15 23:55:38 rpi4 airsaned[22862]: io/hpmud/musb.c 427: Found interface conf=0, iface=0, altset=0, index=2
окт 15 23:55:38 rpi4 airsaned[22862]: io/hpmud/musb.c 389: Active kernel driver on interface=0 ret=0
окт 15 23:55:38 rpi4 airsaned[22862]: io/hpmud/musb.c 535: claimed 7/1/3 interface
окт 15 23:55:39 rpi4 airsaned[22862]: io/hpmud/musb.c 960: new HP-SCAN channel=4 clientCnt=1 channelCnt=2
окт 15 23:55:39 rpi4 airsaned[22862]: io/hpmud/musb.c 975: removed HP-SCAN channel=4 clientCnt=0 channelCnt=1
окт 15 23:55:39 rpi4 airsaned[22862]: io/hpmud/musb.c 561: released 7/1/3 interface
окт 15 23:55:40 rpi4 airsaned[22862]: io/hpmud/musb.c 975: removed HP-MESSAGE channel=1 clientCnt=0 channelCnt=0
окт 15 23:55:40 rpi4 airsaned[22862]: sane_hpaio_cancel: already cancelled!
окт 15 23:55:40 rpi4 airsaned[22862]: io/hpmud/hpmud.c 721: invalid channel_write state
окт 15 23:55:40 rpi4 airsaned[22862]: io/hpmud/pml.c 374: SetPml channel_write failed ret=31

Here's the log running in debug mode:

git commit: 145ea99 (branch makepkg, rev 207+)
build date: 2021-10-15T19:16:40Z
reading device options from '/etc/airsane/options.conf'
enumerating local devices...
sane_init(nullptr, nullptr)
sane_get_devices() ...
... sane_get_devices() -> SANE_Status Success
sane_exit()
found: hpaio:/usb/hp_LaserJet_3380?serial=00CNBN115268 (Hewlett-Packard hp_LaserJet_3380)
stable unique name: hpaio:Hewlett-Packard hp_LaserJet_3380:1
uuid: 8fcc35e8-d849-578c-860a-c338aecd370f
sane_init(nullptr, nullptr)
sane_open(hpaio:/usb/hp_LaserJet_3380?serial=00CNBN115268) -> 0xb357fe58
[source] := "ADF"
sane_close(0xb357fe58)
sane_exit()
published as 'Hewlett-Packard hp_LaserJet_3380'
listening on 127.0.0.1:8090
listening on 192.168.1.254:8090
listening on 172.18.0.1:8090
listening on 172.19.0.1:8090
listening on 172.17.0.1:8090
listening on [::1]:8090
listening on [fe80::dea6:32ff:fe0d:eed6]:8090
listening on [fe80::42:a7ff:fe87:54be]:8090
listening on [fe80::42:21ff:fe08:9ac]:8090
listening on [fe80::f468:e7ff:fe5a:d433]:8090
listening on [fe80::7494:1dff:fe8f:37be]:8090
listening on [fe80::58c4:8eff:fed8:f177]:8090
document format requested: application/pdf
document format used: application/pdf
job kind: ADF single
using color gamma of 0.555555
sane_init(nullptr, nullptr)
sane_open(hpaio:/usb/hp_LaserJet_3380?serial=00CNBN115268) -> 0xaf213440
[mode] := "Color"
[source] := "ADF"
[resolution] := 200dpi
[tl-x] := 0mm
[tl-y] := 0mm
[br-x] := 210mm
[br-y] := 297mm
sane_start(0xaf213440) with options:
[batch-scan] = 0
[br-x] = 210mm
[br-y] = 297mm
[brightness] = 0
[compression] = "JPEG"
[contrast] = 0
[jpeg-quality] = 10
[length-measurement] = "Padded"
[mode] = "Color"
[resolution] = 200dpi
[source] = "ADF"
[tl-x] = 0mm
[tl-y] = 0mm
sane_cancel(0xaf213440)
sane_cancel(0xaf213440)
sane_close(0xaf213440)
sane_exit()
SimulPiscator commented 2 years ago

The [compression] = "JPEG" setting might be a problem. Try compression=None in /etc/airsane/options.conf.

ilya-fedin commented 2 years ago

Looks like airsane doesn't understand that line, I'm still getting [compression] = "JPEG" in debug mode

ilya-fedin commented 2 years ago

Oh, it's because there's a device genesys:.* line and I added the line to the end of the file.

So, the error in normal mode is still the same:

окт 16 00:37:32 rpi4 airsaned[25408]: sane_hpaio_cancel: already cancelled!
окт 16 00:37:32 rpi4 airsaned[25408]: io/hpmud/hpmud.c 721: invalid channel_write state
окт 16 00:37:32 rpi4 airsaned[25408]: io/hpmud/pml.c 374: SetPml channel_write failed ret=31

And I don't see any difference except of compression in debug mode:

git commit: 145ea99 (branch makepkg, rev 207+)
build date: 2021-10-15T19:16:40Z
reading device options from '/etc/airsane/options.conf'
enumerating local devices...
sane_init(nullptr, nullptr)
sane_get_devices() ...
... sane_get_devices() -> SANE_Status Success
sane_exit()
found: hpaio:/usb/hp_LaserJet_3380?serial=00CNBN115268 (Hewlett-Packard hp_LaserJet_3380)
stable unique name: hpaio:Hewlett-Packard hp_LaserJet_3380:1
uuid: 8fcc35e8-d849-578c-860a-c338aecd370f
sane_init(nullptr, nullptr)
sane_open(hpaio:/usb/hp_LaserJet_3380?serial=00CNBN115268) -> 0xb3536370
applying SANE option compression:=None
[compression] := "None" -> reload options
[source] := "ADF"
sane_close(0xb3536370)
sane_exit()
published as 'Hewlett-Packard hp_LaserJet_3380'
listening on 127.0.0.1:8090
listening on 192.168.1.254:8090
listening on 172.18.0.1:8090
listening on 172.19.0.1:8090
listening on 172.17.0.1:8090
listening on [::1]:8090
listening on [fe80::dea6:32ff:fe0d:eed6]:8090
listening on [fe80::42:a7ff:fe87:54be]:8090
listening on [fe80::42:21ff:fe08:9ac]:8090
listening on [fe80::f468:e7ff:fe5a:d433]:8090
listening on [fe80::7494:1dff:fe8f:37be]:8090
listening on [fe80::58c4:8eff:fed8:f177]:8090
document format requested: application/pdf
document format used: application/pdf
job kind: ADF single
using color gamma of 0.555555
sane_init(nullptr, nullptr)
sane_open(hpaio:/usb/hp_LaserJet_3380?serial=00CNBN115268) -> 0xaf20a6a8
[compression] := "None" -> reload options
[mode] := "Color"
[source] := "ADF"
[resolution] := 200dpi
[tl-x] := 0mm
[tl-y] := 0mm
[br-x] := 210mm
[br-y] := 297mm
sane_start(0xaf20a6a8) with options:
[batch-scan] = 0
[br-x] = 210mm
[br-y] = 297mm
[brightness] = 0
[compression] = "None"
[contrast] = 0
[length-measurement] = "Padded"
[mode] = "Color"
[resolution] = 200dpi
[source] = "ADF"
[tl-x] = 0mm
[tl-y] = 0mm
sane_cancel(0xaf20a6a8)
sane_cancel(0xaf20a6a8)
sane_close(0xaf20a6a8)
sane_exit()
ilya-fedin commented 2 years ago

Interesting, looks like airsane sets source to ADF forecfully and I'm not able to override that even with options.conf. scanimage says that the regular default is Auto:

    --source Auto|ADF [Auto]
        Selects the scan source (such as a document-feeder).
ilya-fedin commented 2 years ago

Apparently, that's the reason for fail since I put the sheet into the platen and the feeder is empty

ilya-fedin commented 2 years ago

изображение :thinking:

ilya-fedin commented 2 years ago

I applied such a patch:

diff --git a/server/scanner.cpp b/server/scanner.cpp
index ed789c5..a2268c0 100644
--- a/server/scanner.cpp
+++ b/server/scanner.cpp
@@ -76,6 +76,8 @@ findFlatbedName(const std::vector<std::string>& names)
   auto i = std::find(names.begin(), names.end(), "Flatbed");
   if (i == names.end())
     i = std::find(names.begin(), names.end(), "FlatBed");
+  if (i == names.end())
+    i = std::find(names.begin(), names.end(), "Auto");
   if (i == names.end())
     return "";
   return *i;

And scanning started to work!

SimulPiscator commented 2 years ago

Cool, thank you! But doesn't "Auto" mean "use flatbed if no paper is in ADF"?

ilya-fedin commented 2 years ago

But doesn't "Auto" mean "use flatbed if no paper is in ADF"?

Most likely, yeah. I don't know whether there's any equivalent of 'Auto' in AirScan protocol, so I just made a fast hack to check whether my assumption is right or not :)

SimulPiscator commented 2 years ago

No, there is no equivalent of "Auto" in the AirScan protocol. I don't know how to handle this case.

ilya-fedin commented 2 years ago

I guess 'Auto' can mean only two things in practice:

  1. It's a scanner without a feeder, so it means platen definitely
  2. It's a scanner with a feeder and it will try to scan via feeder and fallback to the platen, so it's a good idea to have it as a fallback for platen scan type when there's no options like 'Flatbed'
SimulPiscator commented 2 years ago

I think you are right, I'll take your patch.