[sane-devel] Suggestion to enhance log file output.

Sun Nov 24 19:14:27 GMT 2024

Hi,
This is a difficult one. Interfaces with the backends are fairly simple. I
wasn't involved when this was formulated but I assume that the simplicity
is deliberate on purpose to keep it flexible.

Generally, I find that this error is returned from a lower level operation
not working as intended. Some of the backends are quite complex and nuance
in the reporting back of issues is often not really possible.
SANE_STATUS_INVAL is a case in point. It could mean practically anything.

If could be that we could expand the API somewhat to allow more verbose
reporting from a backend through a new function call. However, although we
could expand what such as the DLL layer can report back, it would be a bit
of work adding that in. Also it is unlikely that backends would be updated
to make of it, at least in the short term. Many of our backends don't even
have maintainers.

Cheers,
Ralph

On Sun, Nov 24, 2024 at 7:15 AM G.W. Haywood <sane-devel at jubileegroup.co.uk>
wrote:

> Hi there,
>
> We have a HP M1522n all-in-one printer which has been in continual use
> for both printing and scanning for about the past fifteen years.  It's
> connected (only) to our LAN with a static IP in the 192.168.x.x range.
>
> All the workstations on our network are Linux boxes.  Most of the time
> we use the simple-scan front end, but occasionally I'll use scanimage
> at the command line.
>
> Years ago when I first set up networking for the HP I did it manually.
> I lied about the gateway - gave it a nonexistent IP - so it can't talk
> to the Internet even if it tries.  It's been that way ever since.
> Originally I used the HP-supplied software for Linux.  Life was good.
>
> After I upgraded to Debian Buster the scanner stopped responding.
> Printing continued to work just fine.  After much ado I installed
> 'airprint', and it started responding to scan requests once more.
> Never did find out why hpaio: stopped working.
>
> This time I upgraded to Bullseye.  Printing was still OK but the
> scanner wasn't found by scanimage -L.  The scanning system resisted
> several weeks of intermittent attempts to kick it into life.
>
> Finally I tracked down the problem to an apparently damaged shared
> library.  No idea what caused the damage.  It was simple to rectify by
> a reinstall (and curiously enough hpaio: started working again, but I
> guess that's down to something in the Bullseye upgrade).  But it was
> almost by accident that I found the problem, and it took a long time.
>
> I'm not really satisfied with that.
>
> The debug file output is below at [***].  The docs at
>
> http://www.sane-project.org/html/doc012.html
>
> seem to deny that what it contains is possible.  Specfically, section
> 4.3.4 (sane_open) claims that the possible returned values are:
>
> SANE_STATUS_DEVICE_BUSY
> SANE_STATUS_INVAL
> SANE_STATUS_IO_ERROR
> SANE_STATUS_NO_MEM
> SANE_STATUS_ACCESS_DENIED
>
> but the returned value that I saw in the debug output from the command
>
>
> 8<----------------------------------------------------------------------8<----------------------------------------------------------------------
> $ /usr/bin/simple-scan hpaio:/net/HP_LaserJet_M1522n_MFP?ip=192.168.44.169
>
> 8<----------------------------------------------------------------------8<----------------------------------------------------------------------
>
> (output written into the file ~/.cache/simple-scan/simple-scan.log) is
>
> SANE_STATUS_UNSUPPORTED
>
> at +8.12s in the output.
>
> [***] The entire log file output: [***]
>
> 8<----------------------------------------------------------------------8<----------------------------------------------------------------------
> [+0.05s] DEBUG: simple-scan.vala:2012: Starting /usr/bin/simple-scan
> 3.38.1, PID=2919927
> [+0.06s] DEBUG: unsetenv() is not thread-safe and should not be used after
> threads are created
> [+0.08s] DEBUG: _g_io_module_get_default: Found default implementation
> gvfs (GDaemonVfs) for ‘gio-vfs’
> [+0.18s] DEBUG: _g_io_module_get_default: Found default implementation
> dconf (DConfSettingsBackend) for ‘gsettings-backend’
> [+0.29s] DEBUG: app-window.vala:1990: Loading state from
> /home/ged/.cache/simple-scan/state
> [+0.30s] DEBUG: app-window.vala:1969: Restoring window to 1590x844 pixels
> [+0.46s] DEBUG: scanner.vala:1548: sane_init () -> SANE_STATUS_GOOD
> [+0.46s] DEBUG: scanner.vala:1554: SANE version 1.0.31
> [+0.46s] DEBUG: scanner.vala:1615: Requesting redetection of scan devices
> [+0.46s] DEBUG: scanner.vala:828: Processing request
> [+0.55s] DEBUG: app-window.vala:2065: Saving state to
> /home/ged/.cache/simple-scan/state
> [+0.75s] DEBUG: app-window.vala:2065: Saving state to
> /home/ged/.cache/simple-scan/state
> [+6.72s] DEBUG: app-window.vala:2065: Saving state to
> /home/ged/.cache/simple-scan/state
> [+7.08s] DEBUG: simple-scan.vala:1817: Requesting scan at 300 dpi from
> device 'hpaio:/net/HP_LaserJet_M1522n_MFP?ip=192.168.44.169'
> [+7.08s] DEBUG: scanner.vala:1683: Scanner.scan
> ("hpaio:/net/HP_LaserJet_M1522n_MFP?ip=192.168.44.169", dpi=300,
> scan_mode=ScanMode.GRAY, depth=2, type=single, paper_width=0,
> paper_height=0, brightness=0, contrast=48, delay=3000ms)
> [+7.41s] DEBUG: app-window.vala:2065: Saving state to
> /home/ged/.cache/simple-scan/state
> [+7.91s] DEBUG: app-window.vala:2065: Saving state to
> /home/ged/.cache/simple-scan/state
> [+8.12s] DEBUG: scanner.vala:341: sane_get_devices () -> SANE_STATUS_GOOD
> [+8.12s] DEBUG: scanner.vala:828: Processing request
> [+8.12s] DEBUG: scanner.vala:889: sane_open
> ("hpaio:/net/HP_LaserJet_M1522n_MFP?ip=192.168.44.169") ->
> SANE_STATUS_UNSUPPORTED
> [+8.12s] WARNING: scanner.vala:893: Unable to open device: Operation not
> supported
> [+8.28s] DEBUG: app-window.vala:2065: Saving state to
> /home/ged/.cache/simple-scan/state
> [+8.50s] DEBUG: app-window.vala:2065: Saving state to
> /home/ged/.cache/simple-scan/state
> [+11.75s] DEBUG: autosave-manager.vala:201: Deleting autosave records
> [+11.76s] DEBUG: scanner.vala:1711: Stopping scan thread
> [+11.76s] DEBUG: scanner.vala:828: Processing request
> [+11.86s] DEBUG: scanner.vala:1722: sane_exit ()
>
> 8<----------------------------------------------------------------------8<----------------------------------------------------------------------
>
> It wasn't until I came across a post on some forum which suggested
> setting the environment variable SANE_DEBUG_DLL to 255 that I found
> this output on the *terminal*, not in the file:
>
>
> 8<----------------------------------------------------------------------8<----------------------------------------------------------------------
> zeroconf: ZEROCONF_MDNS_HINT: initial scan finished
> zeroconf: device_list wait: OK
> zeroconf: zeroconf_device_list_get: building list of devices
> zeroconf: zeroconf_device_list_get: resulting list:
> API: sane_get_devices(): done
> [16:36:47.074438] [dll] load: searching backend `hpaio' in
> `/usr/lib/aarch64-linux-gnu/sane:/usr/lib/sane:/usr/lib64/sane'
> [16:36:47.074509] [dll] load: trying to load
> `/usr/lib/aarch64-linux-gnu/sane/libsane-hpaio.so.1'
> [16:36:47.074582] [dll] load: dlopen()ing
> `/usr/lib/aarch64-linux-gnu/sane/libsane-hpaio.so.1'
> [16:36:47.075651] [dll] load: dlopen() failed
> (/lib/aarch64-linux-gnu/libhpip.so.0: invalid ELF header)
> [16:36:47.075723] [dll] sane_get_devices: found 0 devices
> [16:36:47.075903] [dll] sane_open: trying to open
> `hpaio://net/HP_LaserJet_M1522n_MFP?ip=192.168.44.169'
> [16:36:47.075988] [dll] init: initializing backend `hpaio'
> [16:36:47.076016] [dll] op_unsupported: call to unsupported backend
> operation
> WSDD: 2001:470:6976:44:96bb:293b:bae0:63b9: done discovery
> WSDD: 192.168.44.15: done discovery
> WSDD: fe80::722b:79fb:927e:f503: done discovery
> zeroconf: ZEROCONF_WSD: initial scan finished
> [16:36:50.017799] [dll] sane_exit: exiting
>
> 8<----------------------------------------------------------------------8<----------------------------------------------------------------------
>
> It seems to me that the log file content could have been a bit more
> forthcoming.  The notion of "operation unsupported" is to me very
> different from that of "broken shared object".
>
> Did I miss something obvious?
>
> Could the error message in the log file conveniently be improved?  It
> would have saved me a *lot* of effort if it had mentioned the broken
> shared object file.
>
> --
>
> 73,
> Ged.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://alioth-lists.debian.net/pipermail/sane-devel/attachments/20241124/247bc2ce/attachment-0001.htm>