airsaned report no scanners available, though scanimage -L reports one

Question

airsaned report no scanners available, though scanimage -L reports one

matkor opened this issue 2 years ago · 4 comments

I am trying to make AirSane build (https://aur.archlinux.org/packages/airsane-git) in archlinux to work.
I am starting airsaned via airsaned.service with:

DynamicUser=true
Group=scanner
SupplementaryGroups=lp
SupplementaryGroups=saned

It runs, but www frontend reports "AirSane Server on / No scanners available" :/
Switching to same user/groups I am able to detect scanner though:

[root@contr ~]# runuser -u airsaned -g scanner -G lp -G saned -- bash
[airsaned@contr root]$ scanimage -L
device `hpaio:/usb/Deskjet_F4200_series?serial=CN94O5828R05BR' is a Hewlett-Packard Deskjet_F4200_series all-in-one

Logs during start:

Jan 15 20:05:05 contr systemd[1]: Started AirSane Imaging Service.
Jan 15 20:05:05 contr airsaned[2104]: Failed to create avahi client: An unexpected D-Bus error occurred (-22)
Jan 15 20:05:05 contr airsaned[2104]: scan/sane/io.c 53: dBus Connection Error (Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network co>
Jan 15 20:05:05 contr airsaned[2104]: scan/sane/io.c 53: dBus Connection Error (Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network co>
Jan 15 20:05:05 contr airsaned[2104]: io/hpmud/musb.c 427: Found interface conf=0, iface=1, altset=0, index=1
Jan 15 20:05:05 contr airsaned[2104]: io/hpmud/musb.c 389: Active kernel driver on interface=1 ret=0
Jan 15 20:05:05 contr airsaned[2104]: io/hpmud/musb.c 535: claimed 7/1/2 interface
Jan 15 20:05:05 contr airsaned[2104]: io/hpmud/musb.c 780: read actual device_id successfully fd=1 len=268
Jan 15 20:05:05 contr airsaned[2104]: io/hpmud/musb.c 561: released 7/1/2 interface
Jan 15 20:05:05 contr airsaned[2104]: io/hpmud/musb.c 427: Found interface conf=0, iface=1, altset=0, index=1
Jan 15 20:05:05 contr airsaned[2104]: io/hpmud/musb.c 389: Active kernel driver on interface=1 ret=0
Jan 15 20:05:05 contr airsaned[2104]: io/hpmud/musb.c 535: claimed 7/1/2 interface
Jan 15 20:05:05 contr airsaned[2104]: io/hpmud/musb.c 780: read actual device_id successfully fd=1 len=268
Jan 15 20:05:05 contr airsaned[2104]: io/hpmud/musb.c 561: released 7/1/2 interface
Jan 15 20:05:05 contr airsaned[2104]: io/hpmud/musb.c 960: new HP-SCAN channel=4 clientCnt=1 channelCnt=1
Jan 15 20:05:05 contr airsaned[2104]: io/hpmud/musb.c 427: Found interface conf=0, iface=2, altset=0, index=7
Jan 15 20:05:05 contr airsaned[2104]: io/hpmud/musb.c 389: Active kernel driver on interface=2 ret=0
Jan 15 20:05:05 contr airsaned[2104]: io/hpmud/musb.c 535: claimed ff/ff/ff interface
Jan 15 20:05:05 contr airsaned[2104]: io/hpmud/musb.c 960: new HP-MESSAGE channel=1 clientCnt=1 channelCnt=2
Jan 15 20:05:06 contr airsaned[2104]: io/hpmud/musb.c 975: removed HP-MESSAGE channel=1 clientCnt=0 channelCnt=1
Jan 15 20:05:06 contr airsaned[2104]: io/hpmud/musb.c 561: released ff/ff/ff interface
Jan 15 20:05:07 contr airsaned[2104]: io/hpmud/musb.c 975: removed HP-SCAN channel=4 clientCnt=0 channelCnt=0
Jan 15 20:05:07 contr airsaned[2104]: No avahi client instance available, not registering service
Jan 15 20:05:07 contr airsaned[2104]: Avahi error when adding service: Operation failed (-1)

Does it mean that scanner is not detectable to airsaned?
Due to message bus security policy can't be made available?
Or any other issue?
TIA for any hints.

Answer 1 · 2023-01-17T11:52:49.000Z

I guess it's related to the avahi failure. If you set MDNS_ANNOUNCE=false in /etc/default/airsane you can check whether it works (apart from mDNS announcement of course). If this works, the problem must be in the avahi dbus connection. BTW, do you have the avahi server installed and running?

Answer 2 · 2023-01-17T12:06:48.000Z

BTW, do you have the avahi server installed and running?

I guess, I have:

[root@contr ~]# systemctl status avahi-daemon.service
● avahi-daemon.service - Avahi mDNS/DNS-SD Stack
     Loaded: loaded (/usr/lib/systemd/system/avahi-daemon.service; enabled; preset: disabled)
     Active: active (running) since Sat 2023-01-14 23:15:58 UTC; 2 days ago
TriggeredBy: ● avahi-daemon.socket
   Main PID: 302 (avahi-daemon)
     Status: "avahi-daemon 0.8 starting up."
      Tasks: 2 (limit: 2243)
     Memory: 1.6M
        CPU: 22.921s
     CGroup: /system.slice/avahi-daemon.service
             ├─302 "avahi-daemon: running [contr.local]"
             └─314 "avahi-daemon: chroot helper"

Jan 14 23:15:58 contr avahi-daemon[302]: New relevant interface lo.IPv6 for mDNS.
Jan 14 23:15:58 contr avahi-daemon[302]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1.
Jan 14 23:15:58 contr avahi-daemon[302]: New relevant interface lo.IPv4 for mDNS.
Jan 14 23:15:58 contr avahi-daemon[302]: Network interface enumeration completed.
Jan 14 23:15:58 contr avahi-daemon[302]: Registering new address record for fe80::921b:eff:fe38:ee39 on enp1s0.*.
Jan 14 23:15:58 contr avahi-daemon[302]: Registering new address record for 192.168.9.48 on enp1s0.IPv4.
Jan 14 23:15:58 contr avahi-daemon[302]: Registering new address record for 192.168.9.11 on enp1s0.IPv4.
Jan 14 23:15:58 contr avahi-daemon[302]: Registering new address record for ::1 on lo.*.
Jan 14 23:15:58 contr avahi-daemon[302]: Registering new address record for 127.0.0.1 on lo.IPv4.
Jan 14 23:15:59 contr avahi-daemon[302]: Server startup complete. Host name is contr.local. Local service cookie is 2060985771.

Answer 3 · 2023-01-17T12:18:39.000Z

What about MDNS_ANNOUNCE=false ?

Answer 4 · 2023-01-17T17:13:53.000Z

you set MDNS_ANNOUNCE=false in /etc/default/airsane you can check whether it works (apart from mDNS announcement of course).

No much difference. Still "No scanners available" :(

Jan 17 16:57:52 contr systemd[1]: Starting AirSane Imaging Service...
Jan 17 16:58:07 contr systemd[1]: Started AirSane Imaging Service.
Jan 17 16:58:07 contr audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=airsaned comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jan 17 16:58:07 contr kernel: audit: type=1130 audit(1673974687.472:675): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=airsaned comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jan 17 16:58:07 contr airsaned[6083]: Failed to create avahi client: An unexpected D-Bus error occurred (-22)
Jan 17 16:58:07 contr airsaned[6083]: scan/sane/io.c 53: dBus Connection Error (Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.)!
Jan 17 16:58:07 contr airsaned[6083]: scan/sane/io.c 53: dBus Connection Error (Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.)!
Jan 17 16:58:07 contr airsaned[6083]: io/hpmud/musb.c 427: Found interface conf=0, iface=1, altset=0, index=1
Jan 17 16:58:07 contr airsaned[6083]: io/hpmud/musb.c 389: Active kernel driver on interface=1 ret=0
Jan 17 16:58:07 contr airsaned[6083]: io/hpmud/musb.c 535: claimed 7/1/2 interface
Jan 17 16:58:07 contr airsaned[6083]: io/hpmud/musb.c 780: read actual device_id successfully fd=1 len=268
Jan 17 16:58:07 contr airsaned[6083]: io/hpmud/musb.c 561: released 7/1/2 interface
Jan 17 16:58:07 contr kernel: Did not find alt setting 1 for intf 0, config 1
Jan 17 16:58:07 contr kernel: Did not find alt setting 1 for intf 0, config 1
Jan 17 16:58:07 contr airsaned[6083]: io/hpmud/musb.c 427: Found interface conf=0, iface=1, altset=0, index=1
Jan 17 16:58:07 contr airsaned[6083]: io/hpmud/musb.c 389: Active kernel driver on interface=1 ret=0
Jan 17 16:58:07 contr airsaned[6083]: io/hpmud/musb.c 535: claimed 7/1/2 interface
Jan 17 16:58:07 contr airsaned[6083]: io/hpmud/musb.c 780: read actual device_id successfully fd=1 len=268
Jan 17 16:58:07 contr airsaned[6083]: io/hpmud/musb.c 561: released 7/1/2 interface
Jan 17 16:58:07 contr airsaned[6083]: io/hpmud/musb.c 960: new HP-SCAN channel=4 clientCnt=1 channelCnt=1
Jan 17 16:58:07 contr airsaned[6083]: io/hpmud/musb.c 427: Found interface conf=0, iface=2, altset=0, index=7
Jan 17 16:58:07 contr airsaned[6083]: io/hpmud/musb.c 389: Active kernel driver on interface=2 ret=0
Jan 17 16:58:07 contr airsaned[6083]: io/hpmud/musb.c 535: claimed ff/ff/ff interface
Jan 17 16:58:07 contr airsaned[6083]: io/hpmud/musb.c 960: new HP-MESSAGE channel=1 clientCnt=1 channelCnt=2
Jan 17 16:58:08 contr airsaned[6083]: io/hpmud/musb.c 975: removed HP-MESSAGE channel=1 clientCnt=0 channelCnt=1
Jan 17 16:58:08 contr airsaned[6083]: io/hpmud/musb.c 561: released ff/ff/ff interface
Jan 17 16:58:09 contr airsaned[6083]: io/hpmud/musb.c 975: removed HP-SCAN channel=4 clientCnt=0 channelCnt=0

airsaned is run:
/usr/bin/airsaned (...) --mdns-announce=false (...)
but seems still tries to "create avahi client" ?