SimulPiscator / AirSane

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

Error: Aborted: ResourcesAreNotReady #43

Closed elsiehupp closed 3 years ago

elsiehupp commented 3 years ago

I had my ScanSnap ix500 set up and working locally using SANE. I briefly had it working in Apple Image Capture with AirSane, but now it isn't working anymore, either locally in simple-scan or over AirSane. There's no error message in Apple Image Capture (it just sits indefinitely), but in localhost:8090 I get the error Error: Aborted: ResourcesAreNotReady when I try to run a scan.

Somewhat strangely, the original ScanSnap device ("FUJITSU ScanSNAP ix500") disappeared from simple-scan and was replaced with a new one (three new ones, in fact), titled "ESCL FUJITSU ScanSnap ix500", and on localhost:8090 there are two identically named scanners, one of which is a dead link. Incidentally, clicking the dead link just caused airsaned to SEGFAULT:

$ sudo -u saned airsaned --debug=true --access-log=-
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: fujitsu:ScanSnap iX500:1200753 (FUJITSU ScanSnap iX500)
sane_init(nullptr, nullptr)
sane_open(fujitsu:ScanSnap iX500:1200753) -> 0x7f99a81501c0
[source] := "ADF Duplex" -> reload options
sane_close(0x7f99a81501c0)
sane_exit()
stable unique name: fujitsu:FUJITSU ScanSnap iX500:1
uuid: 643027f6-f4aa-540e-beb3-2b8dd8266466
published as 'FUJITSU ScanSnap iX500'
found: escl:ScanSnap iX500:1200753 (FUJITSU ScanSnap iX500)
sane_init(nullptr, nullptr)
sane_open(escl:ScanSnap iX500:1200753) -> SANE_Status Invalid argument
sane_exit()
error: failed to open device
listening on 127.0.0.1:8090
listening on 192.168.4.34:8090
listening on [::1]:8090
listening on [fd10:e07c:45dd:1:d87:f4a4:20d7:b2f7]:8090
listening on [fd10:e07c:45dd:1:eeda:2a26:b3f4:3fcc]:8090
listening on [fe80::1599:88b7:1612:3a0e]:8090
127.0.0.1 - - [20/Dec/2020:22:15:39 -0500] "GET /" 200 604 "" "Mozilla/5.0(X11;Ubuntu;Linuxx86_64;rv:84.0)Gecko/20100101Firefox/84.0"
127.0.0.1 - - [20/Dec/2020:22:15:39 -0500] " " 200 -85 "" ""
Segmentation fault

Any idea what's happening here?

SimulPiscator commented 3 years ago

It seems that SANE's escl backend detects the scanner after it has been published by AirSane, i.e. having the escl backend activated seems to result in a loop.

SimulPiscator commented 3 years ago

I'v added an ignore list to avoid loops. Please let me know if it works for you now.

elsiehupp commented 3 years ago

Hi @SimulPiscator, thanks for your quick response! I'm still getting some of the same issues, just... not all of them?

For example, I'm still getting three extra scanners in scanimage and simple-scan, and scanning to them does not work. Here is the terminal output:

$ sudo -u saned scanimage -L
device `fujitsu:ScanSnap iX500:1200753' is a FUJITSU ScanSnap iX500 scanner
device `escl:http://127.0.0.1:8090' is a ESCL FUJITSU ScanSnap iX500 flatbed scanner
device `escl:http://192.168.4.34:8090' is a ESCL FUJITSU ScanSnap iX500 flatbed scanner
device `escl:http://fd10:e07c:45dd:1:c98a:733d:a197:6f53:8090' is a ESCL FUJITSU ScanSnap iX500 flatbed scanner

Incidentally, the ESCL scanner does work in Apple Image Capture, just not in simple-scan. It also works at localhost:8090, though there is still a "phantom" second scanner on the AirSane web interface that, when you click on it, crashes airsaned.

The first scanner (that works) has following URL:

http://localhost:8090/643027f6-f4aa-540e-beb3-2b8dd8266466

And the sceond scanner (that crashes airsaned) has this URL:

http://localhost:8090/b3ae3e77-fd15-540c-9caf-dae67e2a3eaa

If I run airsaned in debug mode, I get the following terminal output:

$ sudo -u saned airsaned --debug=true --access-log=-
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: fujitsu:ScanSnap iX500:1200753 (FUJITSU ScanSnap iX500)
sane_init(nullptr, nullptr)
sane_open(fujitsu:ScanSnap iX500:1200753) -> 0x7f6ff01501c0
[source] := "ADF Duplex" -> reload options
sane_close(0x7f6ff01501c0)
sane_exit()
stable unique name: fujitsu:FUJITSU ScanSnap iX500:1
uuid: 643027f6-f4aa-540e-beb3-2b8dd8266466
published as 'FUJITSU ScanSnap iX500'
found: escl:ScanSnap iX500:1200753 (FUJITSU ScanSnap iX500)
ignoring escl:ScanSnap iX500:1200753
sane_init(nullptr, nullptr)
sane_open(escl:ScanSnap iX500:1200753) -> SANE_Status Invalid argument
sane_exit()
error: failed to open device
listening on 127.0.0.1:8090
listening on 192.168.4.34:8090
listening on [::1]:8090
listening on [fd10:e07c:45dd:1:c98a:733d:a197:6f53]:8090
listening on [fd10:e07c:45dd:1:eeda:2a26:b3f4:3fcc]:8090
listening on [fe80::1599:88b7:1612:3a0e]:8090

and if I click the second URL, it appends the following before terminating:

Segmentation fault

If I deliberately crash airsaned by clicking on the phantom scanner while airsaned is running as a systemctl process, I get the following output:

$ sudo systemctl status airsaned
● airsaned.service - AirSane Imaging Service
     Loaded: loaded (/lib/systemd/system/airsaned.service; enabled; vendor preset: enabled)
     Active: failed (Result: signal) since Thu 2020-12-24 08:50:37 EST; 3s ago
    Process: 15797 ExecStart=/usr/local/bin/airsaned --interface=${INTERFACE} --listen-port=${LISTEN_PORT} --access-log=${ACCESS_LOG} --hotplug=${HOTPLUG} --mdns-announce=${MDNS_ANNOUNCE} --local-scanners-only=${LOCAL_SCANNERS_ONLY} --options-file=${OPTIONS_FILE} (code=killed, signal=SEGV)
   Main PID: 15797 (code=killed, signal=SEGV)

Dec 24 08:50:14 Alpha systemd[1]: Started AirSane Imaging Service.
Dec 24 08:50:37 Alpha systemd[1]: airsaned.service: Main process exited, code=killed, status=11/SEGV
Dec 24 08:50:37 Alpha systemd[1]: airsaned.service: Failed with result 'signal'.

Again, scanning basically works on macOS, now; I'm just seeing the three (nonfunctional) ESCL scanners in scanimage -L and in simple-scan, as well as the "phantom" second scanner on localhost:8090 (but not anywhere else).

The behavior where only the ESCL scanners and not the USB scanner appear with scanimage -L and in simple-scan has been harder for me to reproduce. It has happened precisely once since I installed the updated AirSane, and I haven't been able to get it to appear since. My best guess is that it has something to do with the scanner appearing to be busy or unavailable to SANE due to it being in use by AirSane (and perhaps Apple Image Capture), and this is probably the same scenario where localhost:8090 produced the titular error message of "Error: Aborted: ResourcesAreNotReady". (This is just a guess, though.) It's also possible that the error occurred with the old version of AirSane still running even though I had installed the new one.

elsiehupp commented 3 years ago

The phantom scanner is, indeed, gone, so thank you for taking care of that!

I was looking through the code, and I found the part where AirSane processes and reports errors:

https://github.com/SimulPiscator/AirSane/blob/68ff5705be0df113690fd633c96951a37a29da32/server/scanjob.cpp#L378-L427

I had determined previously that this issue's titular error was being reported by sane as an IO error, and the code confirms that SANE_STATUS_IO_ERROR will trigger PWG_RESOURCES_ARE_NOT_READY. This does not seem to be a particularly useful translation of the sane error code, and none of the other sane errors triggering this error message are any better a match.

Could you consider updating the AirSane error messages that currently show "Error: Aborted: ResourcesAreNotReady" so that they better match the underlying sane errors? More descriptive error messages could make troubleshooting easier.

You could also consider adding extremely basic triage suggestions, such as power-cycling the scanner, which I have found does seem to resolve the scanner sporadically failing to appear with scanimage -L. sudo sane-find-scanner and sudo service udev reload may be helpful under certain circumstances, as well, so suggesting these commands (or others similar to them) in the error strings (or even triggering them automatically before retrying, rather than simply aborting, albeit with protections against indefinite loops) may also be worthwhile.

SimulPiscator commented 3 years ago

The PWG_RESOURCES_ARE_NOT_READY is actually the value of a StatusReason field. Possible values for that field are defined here: https://www.pwg.org/mfd/navigate/PwgSmRev1-185_DocumentStateReasonsWKV.html If you can suggest a better value from this list in response to a SANE_STATUS_IO_ERROR, let me know.

elsiehupp commented 3 years ago

The more generic StateReasons enum has significantly more options: https://www.pwg.org/mfd/navigate/PwgSmRev1-185_StateReasons.html#LinkC36

It would seems that SANE's object model differs from the PWG's object model in that some values of SANE_STATUS correspond to members of DocumentState and DocumentStateReasons while others correspond to JobState and JobStateReasons and yet others correspond to [Service] State and StateReasons.

Looking further at your code, it seems you have hardcoded only two of the six allowed values of state: https://github.com/SimulPiscator/AirSane/blob/eb04a2d95c02a4515546c2d803671e01ea88080a/server/scanner.cpp#L333-L336

While immediately below it temporaryAdfStatusString() returns nonstandard Status values to <scan:AdfState> (which more properly should go under <pwg:State> and <pwg:StateReasons>): https://github.com/SimulPiscator/AirSane/blob/eb04a2d95c02a4515546c2d803671e01ea88080a/server/scanner.cpp#L338-L353 https://github.com/SimulPiscator/AirSane/blob/eb04a2d95c02a4515546c2d803671e01ea88080a/server/scanner.cpp#L811-L815

And any and all SANE_Status() responses are being fed to JobState and JobStateReasons whether or not they are actually applicable to a job: https://github.com/SimulPiscator/AirSane/blob/68ff5705be0df113690fd633c96951a37a29da32/server/scanjob.cpp#L436-L441

Perhaps if AirSane were to provide more Service Status, JobStatus and DocumentStatus responses, Apple Image Capture might be more agreeable towards it. (The error messages would also just be more useful.)

FYI, I'm getting my information from the following document, which provides a lot more contextual explanation than the online schema reference: cs-sm20-scan10-20090410-5108.02.pdf https://ftp.pwg.org/pub/pwg/candidates/cs-sm20-scan10-20090410-5108.02.pdf

SimulPiscator commented 3 years ago

Believe me, Apple Image Capture just completely ignores whatever is contained in the JobState and JobStateReasons fields.

Nevertheless, you are always welcome to create your own fork of AirSane and try whatever modifications you please.

elsiehupp commented 3 years ago

Believe me, Apple Image Capture just completely ignores whatever is contained in the JobState and JobStateReasons fields.

If this is indeed the case, I don't understand why you are piping all of the error messages into these fields. And, further, I don't understand whether that would have any bearing on how Apple Image Capture would respond to DocumentState or [Service]State.

Regardless of what is useful for Apple Image Capture, it would be useful to get more descriptive error messages when running airsaned --debug=true. And, of course, I didn't find the error message in question in Apple Image Capture; I found it in AirSane's own web interface, where there isn't any particular reason to stick to DocumentStateReasons.

Nevertheless, you are always welcome to create your own fork of AirSane and try whatever modifications you please.

I don't really see what your point is, here. Yes, of course, I could try and make these changes myself. But your own process of trial and error is not sufficiently documented for me to avoid finding myself at the same dead ends you apparently did, hence why it remains useful to have this discussion here in order to avoid wasting my time trying to implement unnecessary features.

It seems that you resent the fact that I am scrutinizing your code and trying to talk about it with you. If that is indeed the case, I would like to emphasize that I'm not demanding you actually do anything with my feedback. And even if the things I suggest you have tried in the past and know don't work, it remains useful to me and other potential contributors to have an explanation of how and why that happened.

Also, in all fairness, I'm interacting with GitHub Issue threads as much out of boredom as out of a desire to provide useful feedback. (And actually getting software to work for me personally takes a distant third.) GitHub is just a much less toxic place to spend time than, say, Twitter or Facebook, in large part because the purposes for opening Issues and interacting with them tend to be relatively well defined. If you would rather not get pinged by GitHub, I assume you can customize your notifications, and, again, you are under no obligation to act on or respond to my feedback, especially not under any particular timeframe.

SimulPiscator commented 3 years ago

If this is indeed the case, I don't understand why you are piping all of the error messages into these fields. And, further, I don't understand whether that would have any bearing on how Apple Image Capture would respond to DocumentState or [Service]State.

I'm doing my best to emulate the behavior of an eSCL scanner, and to provide useful information in those fields as good as I can.

I found it in AirSane's own web interface, where there isn't any particular reason to stick to DocumentStateReasons.

The web interface is not much more than a debugging tool. That's why it displays the error information from the XML rather than being more user friendly.

It seems that you resent the fact that I am scrutinizing your code and trying to talk about it with you.

If I resented being scrutinized I wouldn't publish code on Github in the first place. I just don't have the time and energy to again justify all the decisions that went into that code if I cannot see it leads to a useful result.

But your own process of trial and error is not sufficiently documented for me to avoid finding myself at the same dead ends you apparently did, hence why it remains useful to have this discussion here in order to avoid wasting my time trying to implement unnecessary features.

Agreed.

As I wrote in the other thread, what I did was to look at actual eSCL scanner's XML output as far as available on the web, and then disassemble the AirscanScanner plugin of Apple Image Capture to see which information is actually used by Apple Image Capture. For my own flatbed scanner, testing was straightforward. I also used SANE's test backend in order to simulate an ADF scanner, and examined how Apple Image Capture behaved depending on the Scanner Capabilities XML it received.

The only difference I found was that AIC did not show an automatic preview, and hid the preview button when I switched it to ADF input. This of course makes sense, you don't want to consume a page from the ADF for a preview when you can't put it back. But for the actual scanning process, nothing changed: AIC would request a new job, and then retrieve the job's NextDocument URL exactly once before deleting the job.

So I got convinced that the designers of the AirscanScanner plugin had the following user experience in mind: Fill the ADF, choose "Scan into single document" (or so), then press "Scan" once for each page you want to scan from the ADF.