[sane-devel] Looking to add support for Avision AV50F plus scanner

[Ove Laurum]

Thanks Allan,

That makes sense, I hooked up Wireshark and started comparing Windows and
Linux

Looking at Wireshark traces:
Successful Windows power on of Scanner yields hundreds of URB_CONTROL
in/out messages over the USB bus. During this communication the Red LED on
the scanner turns Green
On Linux Power On only yields 20 calls counting Request and Response as two
messages.
The Red LED on the scanner stays Red.
( I have not attached any traces as large emails with attachments seem to
get stuck in some filter until they are manually released, but can put them
using dropbox if it helps )

In order to be able to interpret the traces easier, It was suggested that
most Avision Scanners are SCSI over USB which is pretty standard, so I
tried to google a specification document, but could find nothing, anyone
know where to find such a specification?

If it adheres to a standard SCSI protocol, then perhaps compiling a backend
where I clone and modify the product number for any other Avision Sheet
Feed scanner and test using that may bring us closer.

the scanner is added to  /lib/udev/hwdb.d/20-sane.hwdb and VM rebooted
usb:v0638p2b6a*
 libsane_matched=yes

Are there any more configurations I can do to make the backend treat the
AV50F scanner the same as another Avision Sheet-feed Scanner which IS
supported? Or do I need to clone, modify and recompile the backend to do
that?

cheers, Ove.

On Mon, 9 Sept 2024 at 12:17, m. allan noah <kitno455 at gmail.com> wrote:

> You cannot compare the traces from two different backends. There is no
> expectation that their scanners need the same type of communication, or
> that the backends are coded in the same way.
> Instead, you must get a wireshark trace of the scanner working under
> windows, and reverse engineer the protocol.
>
> allan
>
>
> On Mon, Sep 9, 2024 at 7:09 AM Ove Laurum <laurum.tech at gmail.com> wrote:
>
>> OK some more information gleaned, as per email below, after updating
>> 20-sane.hwdb, there is no difference as far as I can tell, even in the
>> trace using
>> SANE_DEBUG_AVISION=100 scanimage -L
>> the trace showed the same events.
>> Did I miss something??
>>
>> I then looked at the USB wireshark capture and I compared my working
>> Canon LiDE 220 against the non-working Avision AV50F.
>> What I can see is that when I power on the scanners in Linux, I get the
>> same traces in wireshark, and when I run sane-find-scanner I also get
>> the same trace for each device.
>> but when I run scanimage -L I get differences, so far so good, but a bit
>> strange because with the failing scanner, I get:
>> host => URB_CONTROL out
>> scan => URB_CONTROL out
>> host => URB_CONTROL out
>> scan => URB_CONTROL out
>> host => URB_CONTROL in
>> scan => URB_CONTROL in
>> followed by ~30 seconds timeout
>>
>> but on the working scanner I don't get any communication at all when I do scanimage
>> -L
>> ( I do see traffic for the working scanner, but not for scanimage -L)
>>
>> This leads me to believe that there is something before scanimage -L
>> that goes wrong.
>> Trace tells me that the backend is asking sanei_usb.c to communicate
>> with the scanner on the correct device ID, but it is getting a write error
>> back.
>> Could it be another configuration that is required?
>>
>> when I do
>> SANE_DEBUG_SANEI_USB=5 scanimage -L
>> I got some interesting information.
>> I attached the logfile as sanei_usb.ods file (openoffice) to this email
>> Green lines (in the file) are for the working Canon Scanner
>> Yellow Lines for the not working Avision scanner.
>>
>> Successful scanner
>> [16:01:00.053164] [sanei_usb] sanei_usb_open: opened usb device
>> `libusb:001:010' (*dn=0)
>> [16:01:00.053210] [sanei_usb] sanei_usb_close: evaluating environment
>> variable SANE_USB_WORKAROUND
>> [16:01:00.053229] [sanei_usb] sanei_usb_close: closing device 0
>> [16:01:00.053793] [sanei_usb] sanei_usb_scan_devices: marking existing
>> devices
>>
>> failing scanner
>> [16:01:03.786750] [sanei_usb] sanei_usb_open: opened usb device
>> `libusb:001:012' (*dn=1)
>> [16:01:03.786766] [sanei_usb] sanei_usb_write_bulk: trying to write 10
>> bytes
>> [16:01:03.787163] [sanei_usb] sanei_usb_write_bulk: wanted 10 bytes,
>> wrote 10 bytes
>> [16:01:03.787188] [sanei_usb] sanei_usb_read_bulk: trying to read 96 bytes
>> [16:01:04.787997] [sanei_usb] sanei_usb_read_bulk: read failed (still got
>> 0 bytes): Operation timed out
>> [16:01:04.790478] [sanei_usb] sanei_usb_write_bulk: trying to write 10
>> bytes
>> [16:01:04.790834] [sanei_usb] sanei_usb_write_bulk: wanted 10 bytes,
>> wrote 10 bytes
>> [16:01:04.790853] [sanei_usb] sanei_usb_read_bulk: trying to read 96 bytes
>> [16:01:05.792574] [sanei_usb] sanei_usb_read_bulk: read failed (still got
>> 0 bytes): Operation timed out
>> [16:01:05.793384] [sanei_usb] sanei_usb_write_bulk: trying to write 10
>> bytes
>> [16:01:35.794146] [sanei_usb] sanei_usb_write_bulk: write failed:
>> Operation timed out
>> [16:01:35.794795] [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes
>> [16:01:36.295389] [sanei_usb] sanei_usb_read_bulk: read failed (still got
>> 0 bytes): Operation timed out
>> [16:01:36.296025] [sanei_usb] sanei_usb_read_int: trying to read 1 bytes
>> [16:01:36.797312] [sanei_usb] sanei_usb_write_bulk: trying to write 10
>> bytes
>> [16:02:06.799887] [sanei_usb] sanei_usb_write_bulk: write failed:
>> Operation timed out
>> [16:02:06.800591] [sanei_usb] sanei_usb_read_bulk: trying to read 1 bytes
>> [16:02:07.301149] [sanei_usb] sanei_usb_read_bulk: read failed (still got
>> 0 bytes): Operation timed out
>> [16:02:07.301919] [sanei_usb] sanei_usb_read_int: trying to read 1 bytes
>> [16:02:07.819371] [sanei_usb] sanei_usb_scan_devices: marking existing
>> devices
>>
>> This looks like the same flow as we saw in the backend log, but we also
>> see that for the successful scanner the backend is not attempting to
>> communicate with the scanner.
>> And for the failing scanner it claims to write 10 bits, but fails in
>> reading. Operation timed out on a 1 second timer.
>> Is this because the backend already knows how to communicate with the
>> canon scanner and it is only when such information is missing that it tries
>> (and fails) to talk to the Avision scanner?
>>
>> Is there any documentation that it would be good to read to better
>> understand what the backend and sanei_usb is trying to do?
>>
>>
>> Thanks in advance for any helpful pointers
>>
>> Ove/
>>
>>
>> On Sun, 8 Sept 2024 at 14:04, Ove Laurum <laurum.tech at gmail.com> wrote:
>>
>>> Thanks Ralph, I am not familiar with udev, but I added my scanner to the
>>> bottom of the file /lib/udev/hwdb.d/20-sane.hwdb on the VM I have the
>>> Scanner connected to as you suggested
>>> I  did: $ *udevadm control --reload-rules*
>>> No luck
>>> I rebooted the VM but I still can not see the scanner with scanimage -L
>>>
>>> Is the scanner supposed to show up using scanimage -L?
>>>
>>> I also tried the GUI xsane, but it also can not see the scanner.
>>>
>>>
>>> Last 7 lines of 20-sane.hwdb:
>>> # Dell Dell 1235cn
>>> usb:v413Cp5310*
>>>  libsane_matched=yes
>>>
>>> # OVE
>>> usb:v0638p2b6a*
>>>  libsane_matched=yes
>>>
>>> output from lsusb & sane-find-scanner & scanimage -L
>>> root# lsusb
>>> Bus 001 Device 003: ID 0638:2b6a Avision, Inc. AV50F Plus
>>>
>>> root# sane-find-scanner
>>>
>>>   # sane-find-scanner will now attempt to detect your scanner. If the
>>>   # result is different from what you expected, first make sure your
>>>   # scanner is powered up and properly connected to your computer.
>>>
>>>   # No SCSI scanners found. If you expected something different, make
>>> sure that
>>>   # you have loaded a kernel SCSI driver for your SCSI adapter.
>>>
>>> found possible USB scanner (vendor=0x0638 [AVISION], product=0x2b6a
>>> [AV50F Plus]) at libusb:001:003
>>>   # Your USB scanner was (probably) detected. It may or may not be
>>> supported by
>>>   # SANE. Try scanimage -L and read the backend's manpage.
>>>
>>>   # Not checking for parallel port scanners.
>>>
>>>   # Most Scanners connected to the parallel port or other proprietary
>>> ports
>>>   # can't be detected by this program.
>>> root# scanimage -L
>>>
>>> No scanners were identified. If you were expecting something different,
>>> check that the scanner is plugged in, turned on and detected by the
>>> sane-find-scanner tool (if appropriate). Please read the documentation
>>> which came with this software (README, FAQ, manpages).
>>>
>>>
>>> Regards Ove.
>>>
>>> On Wed, 4 Sept 2024 at 19:20, Ralph Little <skelband at gmail.com> wrote:
>>>
>>>> Hi,
>>>>
>>>> On Wed, Sep 4, 2024 at 10:11 AM Ove Laurum <laurum.tech at gmail.com>
>>>> wrote:
>>>>
>>>>> Thanks Ralph,
>>>>>
>>>>> I found the code on GitLab. Very useful.
>>>>>
>>>>> I also managed to add my scanner to the config file
>>>>> /etc/sane.d/avision.conf
>>>>> usb 0x0638 0x2b6a
>>>>>
>>>>
>>>> Great.
>>>>
>>>>
>>>>>
>>>>> I didn't get much of a trace out until I ran it as root, see
>>>>> abbreviated output below
>>>>> SANE_DEBUG_AVISION=100 scanimage -L
>>>>> (I don't think I can use the -d option unless the device is listed
>>>>> with "scanimage -L")
>>>>>
>>>>> When I do:
>>>>> SANE_DEBUG_AVISION=50 sane-find-scanner
>>>>> I get no trace, is that because the backend is not involved at this
>>>>> stage?
>>>>>
>>>>
>>>> Yeah, that won't work. sane-find-scanner is not using the SANE API at
>>>> all. It merely looks for devices that might be scanners.
>>>> You should use scanimage or another SANE frontend instead. This
>>>> *should* work once the avision backend knows about your scanner.
>>>> I *think* that you can use -d avision to pick the first avision device.
>>>>
>>>>
>>>>>
>>>>> In the trace that I did get, it looks like the backend is opening the
>>>>> correct device "libusb:001:003" and tries a first command which is
>>>>> "Inquiry".
>>>>> It builds the query and tries to write it but fails with error code 9.
>>>>>
>>>>> I am running the command as root (not as sudo) so it should not be a
>>>>> permissions issue unless the backend is run by a different user.
>>>>> If I run as an unprivileged user then I do not even get this far. In
>>>>> that case it tries to access the scanner but fails and is not even getting
>>>>> to the stage of Attaching to the scanner.
>>>>> Also worth noting is that my Canon LiDE220 works fine with sane, which
>>>>> is another indicator that it is unlikely a permissions issue.
>>>>>
>>>>
>>>> Permissions are generally handled by udev which has rules based on USB
>>>> ids to give permissions to non-root users.
>>>> Just adding the USB ids to the backend will not be sufficient. You
>>>> *could* add the USB ids to a udev file such as
>>>> /lib/udev/hwdb.d/20-sane.hwdb followed by running something like
>>>>
>>>> *udevadm control --reload-rules*
>>>>
>>>> ...as root. This should allow you to connect to the device as a
>>>> regular scanning user.
>>>>
>>>>
>>>>>
>>>>> So based on the trace and on the source code it looks like it is:
>>>>>
>>>>>    - Attaching to the scanner.
>>>>>    - SANE_Status = SANE_STATUS_GOOD in reply to sanei_usb_open
>>>>>    - starts building an inquiry
>>>>>    - tries to send the inquiry
>>>>>    - fails to do sanei_usb_write_bulk
>>>>>    - sanei_usb.c responds with error
>>>>>
>>>>> How can I see log entries from sanei_usb.c code?
>>>>>
>>>>>
>>>> I believe SANE_DEBUG_SANEI_USB=5 will give you some info about sanei
>>>> USB operations. Greater value gives you more info.
>>>>
>>>> Cheers,
>>>> Ralph
>>>>
>>>
>
> --
> "well, I stand up next to a mountain- and I chop it down with the edge of
> my hand"
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://alioth-lists.debian.net/pipermail/sane-devel/attachments/20240909/225357dc/attachment-0001.htm>