#1381 ESCL: Kyocera ECOSYS returns 503 "busy" on the next flatbed scan unless the finished job is DELETEd

[Axel Mc Allister]

Also filed on GitHub: https://github.com/cyanfish/naps2/issues/906

Hi,

With a Kyocera ECOSYS MA2600cwfx and the ESCL driver, the first flatbed scan works. The next one fails with "The selected scanner is busy" (HTTP 503 on POST /eSCL/ScanJobs), and the scanner then stays locked for about 2 minutes. I've narrowed it down with plain curl requests, so NAPS2 isn't involved in the reproduction. Sending DELETE on the finished job after the final 404 fixes it. NAPS2 already has EsclClient.CancelJob(), which sends that DELETE, so the fix should be small.

Environment

• NAPS2 8.3.2 (Windows 10 22H2 x64), ESCL driver, flatbed (Platen) source
• Kyocera ECOSYS MA2600cwfx, eSCL pwg:Version 2.9, Server: KM-MFP-http/V0.0.1, reached at https://<ip>:9096/eSCL (self-signed certificate)
• The same symptom has been reported for another Kyocera model on SANE's escl backend: sane-project/backends#742 (ECOSYS M3145dn, "wait 2 minutes between scans")

Symptom

1. Scan with an ESCL profile (flatbed). It works.
2. Scan again. It fails at once with "The selected scanner is busy" / 503 (Service Unavailable).
3. Any further attempt fails the same way for about 2 minutes, and then it works again, once.

What the device does (reproduced with curl, no NAPS2)

NAPS2 already does the right thing according to the spec. It calls NextDocument until it gets a 404, and after that ScannerStatus shows the job Completed and the scanner Idle. The Kyocera still rejects the next job:

21:44:13  POST /eSCL/ScanJobs                -> 201 Created (job A)
21:44:13  GET  <jobA>/NextDocument           -> 200 (image)
21:44:24  GET  <jobA>/NextDocument           -> 404
21:44:24  ScannerStatus                      -> Idle, job A = Completed
21:44:26  POST /eSCL/ScanJobs                -> 503 Service Unavailable
21:44:26  ScannerStatus                      -> Processing, job A is back to
                                                Processing / JobScanningAndTransferring,
                                                ImagesCompleted = 0
  ... job A stays "Processing" for ~120 s ...
21:46:26  ScannerStatus                      -> Idle, job A = Canceled (JobCanceledAtDevice)

• A new job is accepted only when the previous job ended as Canceled. When the previous job ended as Completed, the next POST gets 503. In one case it still got 503 107 s after the previous job completed, so this isn't a short cooldown.
• The rejected POST itself reopens the previous job, which then blocks the scanner until the device's ~2-minute timeout. Every retry during that window hits the same wall.
• The device reports ImagesCompleted = 0 for flatbed jobs even after the image has been downloaded. That may be why it doesn't consider the job really finished.

Workaround / proposed fix

Send DELETE <JobUri> after the final NextDocument 404:

21:47:39  POST ScanJobs -> 201   NextDocument -> 200   NextDocument -> 404   DELETE job -> 200   (Idle)
21:47:55  POST ScanJobs -> 201   NextDocument -> 200   NextDocument -> 404   DELETE job -> 200   (Idle)
21:48:05  POST ScanJobs -> 201   NextDocument -> 200   NextDocument -> 404   DELETE job -> 200   (Idle)

Three consecutive flatbed jobs about 10 s apart were all accepted. The DELETE returns 200 even though the job is already Completed, so it looks harmless to send.

In EsclScanDriver.Scan() this could be a call to client.CancelJob(job) once the while (true) loop exits normally, at least for EsclInputSource.Platen. Right now cancelOnce only runs on user cancellation or an exception. Retrying POST /ScanJobs on 503 (as NextDocument already does) would not help on this device, because each rejected POST restarts the 2-minute lock.

I'm happy to test a build or give more logs.

Thanks for NAPS2!