On Sat, Jan 02, 2021 at 09:34:56AM +0100, Marcus Glocker wrote:
> On Fri, Jan 01, 2021 at 07:15:53PM +0000, Natasha Kerensikova wrote:
> 
> > Hello,
> > 
> > I'm only catching up with the thread now, but thanks a lot for including
> > me, I am indeed interested in how this topic is evolve.
> > 
> > FWIW, I have been running with a CURRENT and this patch since April, on
> > my main computer (which I also use for remote working, so it's quite
> > extensively used). But because I'm a bit lazy and need this computer to
> > work, I don't update my CURRENT as often as I should.
> > 
> > I have scanned about a hundred pages, and used common USB devices
> > (keyboard, mouse, KVM masquerading as a hub, flash drive, PTP camera)
> > without any issue whatsoever (except for an sudden shutdown when the
> > power strip got loose from the wall socket, we clearly need a patch to
> > handle such cases).
> > 
> > > > Sorry, I was not clear;  I meant to say that 'scanimage -L' isn't
> > > > recognizing my EPSON ET-2750 device at all.  But in the meantime I
> > > > could get my hands on a CANON CanoScan LiDE 400, which gets
> > > > recognized, and it looks like I see similar issues like you do.
> > > > Based on that I can do some further investigations.
> > > 
> > > It looks like with xhci(4) for some reason the bulk endpoints are
> > > stalling after some operations, which isn't happening with ehci(4).  I
> > > currently can't see why this happens only with xhci(4).  That's why
> > > on your second attempt you see the timeouts happening, because the bulk
> > > endpoints still are in a stalled state.
> > 
> > Did you check my summary in
> > https://marc.info/?l=openbsd-tech&m=158729024415324&w=2 ?
> > 
> > If you have not already ruled it out, it seems worth considering:
> > XHCI-specific packet loss detection feature, which uses alternating PID
> > between DATA0 and DATA1, and only works when the OS and the device agree
> > on the current PID for the next packet.
> > 
> > When they get out of sync, e.g. because the OS kept the DATA1 state
> > after the device reset its on state to DATA0, the OS will send a DATA1
> > packet which will be ignored by the device as if a previous DATA0 was
> > lost so that both a retransmitted. Maybe the OS retries, still with
> > DATA1, until a timeout occurs.
> > 
> > AFAIU, usbd_clear_endpoint_stall() is used for the side effect of both
> > resetting the OS-side state to DATA0 (which I guess is done by
> > usbd_clear_endpoint_toggle()) and the device-side state through the
> > associated request UR_CLEAR_FAEATURE/UF_ENDPOINT_HALT.
> > 
> > > Using usbd_clear_endpoint_stall() at the pipe closing routine simply
> > > resets all the endpoints, which is why on the next attempt the
> > > transfers are working fine again.  That's probably why this was called
> > > a workaround, because we should understand why the endpoints are
> > > getting stalled in a first line with xhci(4).
> > 
> > I'm not sure what exactly is going on in your setup, but on mine the
> > stall came from the previous use which left the device and the OS
> > out-of-sync. Hence USB scanner working only once, because they are in
> > sync when both power up and get out-of-sync after the first use.
> > 
> > I don't remember whether I tracked out whether OpenBSD-side state is
> > reset when it shouldn't (e.g. because it's not stored after closing the
> > device) or not reset when it should (e.g. because it's stored despite
> > the device resetting its own state). But if I did I have completely
> > forgotten the conclusion.
> > 
> > 
> > Hoping this helps,
> > Natasha
> 
> Thanks for your feedback.
> 
> I was not following up the initial conversation on this thread, so I
> probably missed a lot of what was already discussed.
> 
> I'm also not very familiar with any xhci specific packet loss feature
> mechanism.  But if there was already an proposal from patrick@ to come
> over this by doing an EP clearing on device open, I've just tested the
> following diff, and it makes my scanner reliably fail now with xhci :-)
> 
> I saw that you already had a similar diff tested unsuccessfully.
> Never the less, can you give this one another spin please on a freshly
> updated -current kernel, and see if it makes any difference for you
> as well?
> 
> 
> Index: dev/usb/ugen.c
> ===================================================================
> RCS file: /cvs/src/sys/dev/usb/ugen.c,v
> retrieving revision 1.109
> diff -u -p -u -p -r1.109 ugen.c
> --- dev/usb/ugen.c    25 Dec 2020 12:59:52 -0000      1.109
> +++ dev/usb/ugen.c    2 Jan 2021 08:22:42 -0000
> @@ -389,6 +389,10 @@ ugenopen(dev_t dev, int flag, int mode, 
>               }
>       }
>       sc->sc_is_open[endpt] = 1;
> +
> +     if (sce->pipeh)
> +             usbd_clear_endpoint_stall(sce->pipeh);
> +
>       return (0);
>  }
>  

Above diff makes my scanner fail straight away.

# unset SANE_DEBUG_PIXMA
# unset SANE_DEBUG_SANEI_USB
# time scanimage --device-name pixma:04A91762_860FE4 \
        --format png --mode gray --resolution 300 --output-file 
debug-scan-loop.png
mem:device-resp.xml:7: parser error : Opening and ending tag mismatch: contents 
line 3 and param_set
                </ivec:param_set>
                                 ^
mem:device-resp.xml:8: parser error : Opening and ending tag mismatch: cmd line 
3 and ivec:contents
        </ivec:contents>
                        ^
mem:device-resp.xml:9: parser error : Extra content at the end of the document
</cmd>
^
scanimage: sane_read: Error during device I/O
    0m00.62s real     0m00.00s user     0m00.02s system


# export SANE_DEBUG_SANEI_USB=5
# export SANE_DEBUG_PIXMA=21
# time scanimage --device-name pixma:04A91762_860FE4 \
        --format png --mode gray --resolution 300 --output-file 
debug-scan-loop.png
[09:51:40.895749] [sanei_debug] Setting debug level of pixma to 21.
[09:51:40.896472] [pixma] pixma is compiled without pthread support.
[09:51:40.896805] [pixma] pixma version 0.28.5
[09:51:40.897076] [sanei_debug] Setting debug level of sanei_usb to 5.
[09:51:40.897360] [sanei_usb] sanei_usb_init: initializing libusb-1.0
[09:51:40.898519] [sanei_usb] sanei_usb_scan_devices: marking existing devices
[09:51:40.898609] [sanei_usb] libusb_scan_devices: Looking for libusb-1.0 
devices
[09:51:40.900742] [sanei_usb] libusb_scan_devices: device 0x1022/0x0000 at 
000:001 looks like a root hub
[09:51:40.904334] [sanei_usb] libusb_scan_devices: found libusb-1.0 device 
(0x04a9/0x1762) interface 0 at libusb:000:002
[09:51:40.904398] [sanei_usb] store_device: add dn 0 with libusb:000:002
[09:51:40.904457] [sanei_usb] libusb_scan_devices: device 0x1022/0x0000 at 
001:001 looks like a root hub
[09:51:40.905824] [sanei_usb] libusb_scan_devices: device 0x0438/0x7900, 
interface 0 doesn't look like a scanner (9/9)
[09:51:40.905870] [sanei_usb] libusb_scan_devices: device 0x0438/0x7900 at 
001:002: no suitable interfaces
[09:51:40.906198] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1709
[09:51:40.906339] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x170a
[09:51:40.906437] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x170b
[09:51:40.906459] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x170c
[09:51:40.906582] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1712
[09:51:40.906652] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x172b
[09:51:40.906689] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1714
[09:51:40.906738] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1715
[09:51:40.906872] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1716
[09:51:40.906965] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1717
[09:51:40.907007] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1718
[09:51:40.907057] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1719
[09:51:40.907145] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1721
[09:51:40.907223] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1722
[09:51:40.907266] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1723
[09:51:40.907306] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1724
[09:51:40.907328] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1725
[09:51:40.907395] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1727
[09:51:40.907466] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1728
[09:51:40.907640] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1729
[09:51:40.907678] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x172c
[09:51:40.907729] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x171c
[09:51:40.907765] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x172e
[09:51:40.907819] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x172f
[09:51:40.907852] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1730
[09:51:40.907893] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1731
[09:51:40.907914] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1732
[09:51:40.908002] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1733
[09:51:40.908043] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1734
[09:51:40.908082] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1736
[09:51:40.908103] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1737
[09:51:40.908171] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1735
[09:51:40.908192] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1741
[09:51:40.908245] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1742
[09:51:40.908350] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1743
[09:51:40.908479] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x174d
[09:51:40.908530] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x174e
[09:51:40.908568] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x174f
[09:51:40.908589] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1750
[09:51:40.908639] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x173f
[09:51:40.908666] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x173e
[09:51:40.908687] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x173d
[09:51:40.908728] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x173c
[09:51:40.908750] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x173a
[09:51:40.908814] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x173b
[09:51:40.908916] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1746
[09:51:40.908944] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1747
[09:51:40.908965] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1748
[09:51:40.909041] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1749
[09:51:40.909113] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x174a
[09:51:40.909133] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1751
[09:51:40.909157] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1752
[09:51:40.909178] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1753
[09:51:40.909198] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1754
[09:51:40.909268] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1755
[09:51:40.909362] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1757
[09:51:40.909401] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1758
[09:51:40.909489] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1759
[09:51:40.909556] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x175b
[09:51:40.909610] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x175c
[09:51:40.909717] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x175d
[09:51:40.909758] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x175e
[09:51:40.909778] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x175a
[09:51:40.909849] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1763
[09:51:40.909869] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1761
[09:51:40.909934] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1767
[09:51:40.909983] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x175f
[09:51:40.910054] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1760
[09:51:40.910093] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1762
[09:51:40.910268] [pixma] pixma_collect_devices() found Canon PIXMA MG3200 
Series at libusb:000:002
[09:51:40.910343] [sanei_usb] sanei_usb_open: trying to open device 
`libusb:000:002'
[09:51:40.916044] [sanei_usb] sanei_usb_open: configuration nr: 0
[09:51:40.916132] [sanei_usb] sanei_usb_open:     interface nr: 0
[09:51:40.916154] [sanei_usb] sanei_usb_open:   alt_setting nr: 0
[09:51:40.916185] [sanei_usb] sanei_usb_open: endpoint nr: 0
[09:51:40.916207] [sanei_usb] sanei_usb_add_endpoint: direction: 0, address: 7, 
transfer_type: 2
[09:51:40.916245] [sanei_usb] sanei_usb_add_endpoint: found bulk-out endpoint 
(address 0x07)
[09:51:40.916283] [sanei_usb] sanei_usb_open: endpoint nr: 1
[09:51:40.916304] [sanei_usb] sanei_usb_add_endpoint: direction: 128, address: 
136, transfer_type: 2
[09:51:40.916326] [sanei_usb] sanei_usb_add_endpoint: found bulk-in endpoint 
(address 0x88)
[09:51:40.916364] [sanei_usb] sanei_usb_open: endpoint nr: 2
[09:51:40.916397] [sanei_usb] sanei_usb_add_endpoint: direction: 128, address: 
137, transfer_type: 3
[09:51:40.916418] [sanei_usb] sanei_usb_add_endpoint: found interrupt-in 
endpoint (address 0x89)
[09:51:40.916440] [sanei_usb] sanei_usb_open: configuration nr: 0
[09:51:40.916519] [sanei_usb] sanei_usb_open:     interface nr: 1
[09:51:40.916544] [sanei_usb] sanei_usb_open:   alt_setting nr: 0
[09:51:40.916586] [sanei_usb] sanei_usb_open: interface 1 not detected as a 
scanner by sanei_usb_init, ignoring.
[09:51:40.916619] [sanei_usb] sanei_usb_open: opened usb device 
`libusb:000:002' (*dn=0)
[09:51:40.916865] [sanei_usb] sanei_usb_control_msg: rtype = 0x80, req = 6, 
value = 256, index = 0, len = 18
[09:51:40.918385] [sanei_usb] sanei_usb_control_msg: rtype = 0x80, req = 6, 
value = 768, index = 0, len = 4
[09:51:40.919081] [sanei_usb] sanei_usb_control_msg: rtype = 0x80, req = 6, 
value = 771, index = 1033, len = 44
[09:51:40.919898] [sanei_usb] sanei_usb_close: evaluating environment variable 
SANE_USB_WORKAROUND
[09:51:40.919940] [sanei_usb] sanei_usb_close: closing device 0
[09:51:40.920061] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1764
[09:51:40.920106] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1765
[09:51:40.920142] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1766
[09:51:40.920166] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1768
[09:51:40.920250] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1769
[09:51:40.920302] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x176a
[09:51:40.920323] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x176b
[09:51:40.920361] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x176c
[09:51:40.920386] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x176d
[09:51:40.920407] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x176e
[09:51:40.920462] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1771
[09:51:40.920489] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1770
[09:51:40.920510] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x176f
[09:51:40.920547] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1772
[09:51:40.920573] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1774
[09:51:40.920594] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1775
[09:51:40.920615] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1776
[09:51:40.920635] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1777
[09:51:40.920690] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1778
[09:51:40.920717] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1793
[09:51:40.920766] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1779
[09:51:40.920835] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1792
[09:51:40.920859] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x177a
[09:51:40.920880] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x177b
[09:51:40.920901] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x177c
[09:51:40.920921] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x177e
[09:51:40.920942] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x177f
[09:51:40.920963] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1780
[09:51:40.921012] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1788
[09:51:40.921054] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1787
[09:51:40.921086] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1789
[09:51:40.921107] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x178a
[09:51:40.921166] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x178b
[09:51:40.921193] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x178c
[09:51:40.921244] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x178d
[09:51:40.921265] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x178e
[09:51:40.921312] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1794
[09:51:40.921355] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1795
[09:51:40.921428] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x179f
[09:51:40.921449] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1800
[09:51:40.921514] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1801
[09:51:40.921575] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1802
[09:51:40.921596] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x180b
[09:51:40.921644] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x180c
[09:51:40.921665] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x181e
[09:51:40.921685] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x181d
[09:51:40.921724] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1822
[09:51:40.921745] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1825
[09:51:40.921765] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1827
[09:51:40.921813] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1828
[09:51:40.921855] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x178f
[09:51:40.921930] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1790
[09:51:40.921970] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1820
[09:51:40.922054] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1823
[09:51:40.922075] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1824
[09:51:40.922159] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x185c
[09:51:40.922221] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1912
[09:51:40.922241] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1913
[09:51:40.922262] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1821
[09:51:40.922320] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x183a
[09:51:40.922351] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x183b
[09:51:40.922372] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x183d
[09:51:40.922410] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x183e
[09:51:40.922431] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x183f
[09:51:40.922451] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1840
[09:51:40.922471] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1841
[09:51:40.922492] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1842
[09:51:40.922512] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1843
[09:51:40.922545] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1844
[09:51:40.922620] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1845
[09:51:40.922653] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1846
[09:51:40.922735] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1847
[09:51:40.922807] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1854
[09:51:40.922845] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1855
[09:51:40.922896] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1856
[09:51:40.922933] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1857
[09:51:40.922954] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1858
[09:51:40.923019] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1859
[09:51:40.923040] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x185a
[09:51:40.923095] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x185b
[09:51:40.923148] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x185d
[09:51:40.923169] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x185e
[09:51:40.923189] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1863
[09:51:40.923209] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1865
[09:51:40.923229] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1866
[09:51:40.923290] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1869
[09:51:40.923311] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1873
[09:51:40.923358] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x188b
[09:51:40.923378] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x188c
[09:51:40.923399] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x188d
[09:51:40.923432] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x188e
[09:51:40.923482] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x188f
[09:51:40.923526] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1891
[09:51:40.923579] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1892
[09:51:40.923642] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1893
[09:51:40.923707] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1894
[09:51:40.923738] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x18a2
[09:51:40.923785] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x18a3
[09:51:40.923806] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1706
[09:51:40.923862] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1708
[09:51:40.923892] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1707
[09:51:40.923912] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x2635
[09:51:40.923946] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x261f
[09:51:40.923967] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x263c
[09:51:40.923987] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x263d
[09:51:40.924007] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x263f
[09:51:40.924055] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x263e
[09:51:40.924111] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x2630
[09:51:40.924139] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x264d
[09:51:40.924160] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x262f
[09:51:40.924180] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x264c
[09:51:40.924241] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x265d
[09:51:40.924298] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x265e
[09:51:40.924325] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x265f
[09:51:40.924373] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x2660
[09:51:40.924394] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x26e6
[09:51:40.924414] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x170d
[09:51:40.924434] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x170e
[09:51:40.924482] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1713
[09:51:40.924502] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x171a
[09:51:40.924548] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x171b
[09:51:40.924604] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1726
[09:51:40.924644] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1901
[09:51:40.924664] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x172d
[09:51:40.924704] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1740
[09:51:40.924796] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1908
[09:51:40.924879] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x174b
[09:51:40.924904] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x1756
[09:51:40.924924] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x190d
[09:51:40.924944] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x26b5
[09:51:40.924975] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x26a3
[09:51:40.925030] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x26b0
[09:51:40.925050] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x26ef
[09:51:40.925070] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x26ed
[09:51:40.925101] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x26ec
[09:51:40.925121] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x26ee
[09:51:40.925157] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x26b4
[09:51:40.925177] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x2684
[09:51:40.925232] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x2686
[09:51:40.925266] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x2737
[09:51:40.925286] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x2738
[09:51:40.925331] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x2736
[09:51:40.925351] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x2759
[09:51:40.925371] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x2774
[09:51:40.925418] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x2773
[09:51:40.925438] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x275a
[09:51:40.925459] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x2779
[09:51:40.925518] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x2708
[09:51:40.925539] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x2775
[09:51:40.925559] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x264e
[09:51:40.925580] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x264f
[09:51:40.925627] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x2659
[09:51:40.925648] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x2707
[09:51:40.925668] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x26f9
[09:51:40.925728] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x26fa
[09:51:40.925790] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x2742
[09:51:40.925837] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x2743
[09:51:40.925897] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x277a
[09:51:40.925918] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x278e
[09:51:40.925938] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x27a6
[09:51:40.925959] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x27a8
[09:51:40.926066] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x27a9
[09:51:40.926090] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x27b4
[09:51:40.926110] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x27b5
[09:51:40.926146] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x27c0
[09:51:40.926178] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x27c2
[09:51:40.926210] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x27d1
[09:51:40.926231] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x27d2
[09:51:40.926251] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x27e1
[09:51:40.926271] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x27e4
[09:51:40.926309] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x27e5
[09:51:40.926330] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x27e1
[09:51:40.926350] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x27e2
[09:51:40.926388] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x27e5
[09:51:40.926441] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x27e8
[09:51:40.926469] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x27ed
[09:51:40.926524] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x27f0
[09:51:40.926544] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x27f1
[09:51:40.926564] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x27f4
[09:51:40.926584] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x27fb
[09:51:40.926633] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x27fc
[09:51:40.926680] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x27fe
[09:51:40.926749] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x27fd
[09:51:40.926811] [sanei_usb] sanei_usb_find_devices: vendor=0x04a9, 
product=0x2823
[09:51:41.479180] [pixma] pixma_open(): Canon PIXMA MG3200 Series
[09:51:41.479305] [sanei_usb] sanei_usb_open: trying to open device 
`libusb:000:002'
[09:51:41.487158] [sanei_usb] sanei_usb_open: configuration nr: 0
[09:51:41.487273] [sanei_usb] sanei_usb_open:     interface nr: 0
[09:51:41.487311] [sanei_usb] sanei_usb_open:   alt_setting nr: 0
[09:51:41.487369] [sanei_usb] sanei_usb_open: endpoint nr: 0
[09:51:41.487404] [sanei_usb] sanei_usb_add_endpoint: direction: 0, address: 7, 
transfer_type: 2
[09:51:41.487427] [sanei_usb] sanei_usb_add_endpoint: found bulk-out endpoint 
(address 0x07)
[09:51:41.487452] [sanei_usb] sanei_usb_add_endpoint: we already have a 
bulk-out endpoint (address: 0x07), ignoring the new one
[09:51:41.487475] [sanei_usb] sanei_usb_open: endpoint nr: 1
[09:51:41.487495] [sanei_usb] sanei_usb_add_endpoint: direction: 128, address: 
136, transfer_type: 2
[09:51:41.487517] [sanei_usb] sanei_usb_add_endpoint: found bulk-in endpoint 
(address 0x88)
[09:51:41.487539] [sanei_usb] sanei_usb_add_endpoint: we already have a bulk-in 
endpoint (address: 0x88), ignoring the new one
[09:51:41.487607] [sanei_usb] sanei_usb_open: endpoint nr: 2
[09:51:41.487663] [sanei_usb] sanei_usb_add_endpoint: direction: 128, address: 
137, transfer_type: 3
[09:51:41.487704] [sanei_usb] sanei_usb_add_endpoint: found interrupt-in 
endpoint (address 0x89)
[09:51:41.487751] [sanei_usb] sanei_usb_add_endpoint: we already have a 
interrupt-in endpoint (address: 0x89), ignoring the new one
[09:51:41.487809] [sanei_usb] sanei_usb_open: configuration nr: 0
[09:51:41.487829] [sanei_usb] sanei_usb_open:     interface nr: 1
[09:51:41.487880] [sanei_usb] sanei_usb_open:   alt_setting nr: 0
[09:51:41.487994] [sanei_usb] sanei_usb_open: interface 1 not detected as a 
scanner by sanei_usb_init, ignoring.
[09:51:41.488068] [sanei_usb] sanei_usb_open: opened usb device 
`libusb:000:002' (*dn=0)
[09:51:41.488545] [pixma] *mp150_open***** This is a generation 5 scanner.  
*****
[09:51:41.488968] [pixma] *control_option***** gamma = 2.199997 *
[09:51:41.489148] [pixma] *control_option***** table size = 1024 *
[09:51:41.493739] [pixma] Reader task id=90493 (forked)
[09:51:41.496203] [pixma] Reader task started
[09:51:41.496855] [pixma]
[09:51:41.496912] [pixma] pixma_scan(): start
[09:51:41.496957] [pixma]   line_size=2552 image_size=8952416 channels=1 depth=8
[09:51:41.497044] [pixma]   dpi=300x300 offset=(0,0) dimension=2552x3508
[09:51:41.497117] [pixma]   gamma=2.199997 gamma_table=0x9ccf672fb38 source=0
[09:51:41.497341] [pixma]   threshold=127 threshold_curve=0
[09:51:41.497406] [pixma]   adf-wait=0
[09:51:41.497451] [pixma]   ADF page count: 0
[09:51:41.498092] [sanei_usb] sanei_usb_write_bulk: trying to write 288 bytes
[09:51:41.501889] [sanei_usb] sanei_usb_write_bulk: wanted 288 bytes, wrote 288 
bytes
[09:51:41.502165] [pixma] OUT  T=0.605 len=288
[09:51:41.502232] [pixma]  00000000:3c 3f 78 6d 6c 20 76 65  72 73 69 6f 6e 3d 
22 31     <?xml ve rsion="1
[09:51:41.502259] [pixma]  00000010:2e 30 22 20 65 6e 63 6f  64 69 6e 67 3d 22 
75 74     .0" enco ding="ut
[09:51:41.502281] [pixma]  00000020:66 2d 38 22 20 3f 3e 3c  63 6d 64 20 78 6d 
6c 6e     f-8" ?>< cmd xmln
[09:51:41.502301] [pixma]  00000030:73 3a 69 76 65 63 3d 22  68 74 74 70 3a 2f 
2f 77     s:ivec=" http://w
[09:51:41.502322] [pixma]  00000040:77 77 2e 63 61 6e 6f 6e  2e 63 6f 6d 2f 6e 
73 2f     ww.canon .com/ns/
[09:51:41.502374] [pixma]  00000050:63 6d 64 2f 32 30 30 38  2f 30 37 2f 63 6f 
6d 6d     cmd/2008 /07/comm
[09:51:41.502418] [pixma]  00000060:6f 6e 2f 22 3e 3c 69 76  65 63 3a 63 6f 6e 
74 65     on/"><iv ec:conte
[09:51:41.502444] [pixma]  00000070:6e 74 73 3e 3c 69 76 65  63 3a 6f 70 65 72 
61 74     nts><ive c:operat
[09:51:41.502464] [pixma]  00000080:69 6f 6e 3e 53 74 61 72  74 4a 6f 62 3c 2f 
69 76     ion>Star tJob</iv
[09:51:41.502484] [pixma]  00000090:65 63 3a 6f 70 65 72 61  74 69 6f 6e 3e 3c 
69 76     ec:opera tion><iv
[09:51:41.502622] [pixma]  000000a0:65 63 3a 70 61 72 61 6d  5f 73 65 74 20 73 
65 72     ec:param _set ser
[09:51:41.502642] [pixma]  000000b0:76 69 63 65 74 79 70 65  3d 22 73 63 61 6e 
22 3e     vicetype ="scan">
[09:51:41.502689] [pixma]  000000c0:3c 69 76 65 63 3a 6a 6f  62 49 44 3e 30 30 
30 30     <ivec:jo bID>0000
[09:51:41.502807] [pixma]  000000d0:30 30 30 31 3c 2f 69 76  65 63 3a 6a 6f 62 
49 44     0001</iv ec:jobID
[09:51:41.502862] [pixma]  000000e0:3e 3c 69 76 65 63 3a 62  69 64 69 3e 31 3c 
2f 69     ><ivec:b idi>1</i
[09:51:41.502911] [pixma]  000000f0:76 65 63 3a 62 69 64 69  3e 3c 2f 69 76 65 
63 3a     vec:bidi ></ivec:
[09:51:41.502960] [pixma]  00000100:70 61 72 61 6d 5f 73 65  74 3e 3c 2f 69 76 
65 63     param_se t></ivec
[09:51:41.503126] [pixma]  00000110:3a 63 6f 6e 74 65 6e 74  73 3e 3c 2f 63 6d 
64 3e     :content s></cmd>
[09:51:41.503154] [pixma]
[09:51:41.503337] [sanei_usb] sanei_usb_read_bulk: trying to read 1024 bytes
[09:51:41.512547] [sanei_usb] sanei_usb_read_bulk: wanted 1024 bytes, got 272 
bytes
[09:51:41.512649] [pixma] IN   T=0.615 len=272
[09:51:41.512701] [pixma]  00000000:3c 3f 78 6d 6c 20 76 65  72 73 69 6f 6e 3d 
22 31     <?xml ve rsion="1
[09:51:41.512731] [pixma]  00000010:2e 30 22 20 65 6e 63 6f  64 69 6e 67 3d 22 
75 74     .0" enco ding="ut
[09:51:41.512752] [pixma]  00000020:66 2d 38 22 20 3f 3e 0d  0a 3c 63 6d 64 20 
78 6d     f-8" ?>. .<cmd xm
[09:51:41.512773] [pixma]  00000030:6c 6e 73 3a 69 76 65 63  3d 22 68 74 74 70 
3a 2f     lns:ivec ="http:/
[09:51:41.512794] [pixma]  00000040:2f 77 77 77 2e 63 61 6e  6f 6e 2e 63 6f 6d 
2f 6e     /www.can on.com/n
[09:51:41.512814] [pixma]  00000050:73 2f 63 6d 64 2f 32 30  30 38 2f 30 37 2f 
63 6f     s/cmd/20 08/07/co
[09:51:41.512834] [pixma]  00000060:6d 6d 6f 6e 2f 22 3e 0d  0a 09 3c 69 76 65 
63 3a     mmon/">. ..<ivec:
[09:51:41.512854] [pixma]  00000070:63 6f 6e 74 65 6e 74 73  3e 0d 0a 09 09 3c 
69 76     contents >....<iv
[09:51:41.512875] [pixma]  00000080:65 63 3a 6f 70 65 72 61  74 69 6f 6e 3e 3c 
2f 69     ec:opera tion></i
[09:51:41.512924] [pixma]  00000090:76 65 63 3a 6f 70 65 72  61 74 69 6f 6e 3e 
0d 0a     vec:oper ation>..
[09:51:41.512944] [pixma]  000000a0:09 09 09 3c 69 76 65 63  3a 72 65 73 70 6f 
6e 73     ...<ivec :respons
[09:51:41.512964] [pixma]  000000b0:65 3e 4f 4b 3c 2f 69 76  65 63 3a 72 65 73 
70 6f     e>OK</iv ec:respo
[09:51:41.513064] [pixma]  000000c0:6e 73 65 3e 0d 0a 09 09  09 3c 69 76 65 63 
3a 72     nse>.... .<ivec:r
[09:51:41.513167] [pixma]  000000d0:65 73 70 6f 6e 73 65 5f  64 65 74 61 69 6c 
2f 3e     esponse_ detail/>
[09:51:41.513188] [pixma]  000000e0:0d 0a 09 09 3c 2f 69 76  65 63 3a 70 61 72 
61 6d     ....</iv ec:param
[09:51:41.513240] [pixma]  000000f0:5f 73 65 74 3e 0d 0a 09  3c 2f 69 76 65 63 
3a 63     _set>... </ivec:c
[09:51:41.513260] [pixma]  00000100:6f 6e 74 65 6e 74 73 3e  0d 0a 3c 2f 63 6d 
64 3e     ontents> ..</cmd>
[09:51:41.513280] [pixma]
[09:51:41.513464] [pixma] XML message sent to scanner:
<?xml version="1.0" encoding="utf-8" ?><cmd 
xmlns:ivec="http://www.canon.com/ns/cmd/2008/07/common/";><ivec:contents><ivec:operation>StartJob</ivec:operation><ivec:param_set
 
servicetype="scan"><ivec:jobID>00000001</ivec:jobID><ivec:bidi>1</ivec:bidi></ivec:param_set></ivec:contents></cmd>
[09:51:41.513488] [pixma] XML response back from scanner:
<?xml version="1.0" encoding="utf-8" ?>
<cmd xmlns:ivec="http://www.canon.com/ns/cmd/2008/07/common/";>
        <ivec:contents>
                <ivec:operation></ivec:operation>
                        <ivec:response>OK</ivec:response>
                        <ivec:response_detail/>
                </ivec:param_set>
        </ivec:contents>
</cmd>
mem:device-resp.xml:7: parser error : Opening and ending tag mismatch: contents 
line 3 and param_set
                </ivec:param_set>
                                 ^
mem:device-resp.xml:8: parser error : Opening and ending tag mismatch: cmd line 
3 and ivec:contents
        </ivec:contents>
                        ^
mem:device-resp.xml:9: parser error : Extra content at the end of the document
</cmd>
^
[09:51:41.517910] [pixma] unable to parse xml response
[09:51:41.518030] [pixma] pixma_scan() failed EPROTO
[09:51:41.518602] [pixma] Reader task terminated: EPROTO
[09:51:41.518615] [pixma] read_image():reader task closed the pipe:0 bytes 
received, 8952416 bytes expected
scanimage: sane_read: Error during device I/O
[09:51:41.522056] [pixma] pixma_close(): Canon PIXMA MG3200 Series
[09:51:41.522388] [sanei_usb] sanei_usb_close: evaluating environment variable 
SANE_USB_WORKAROUND
[09:51:41.522430] [sanei_usb] sanei_usb_close: closing device 0
[09:51:41.523339] [sanei_usb] sanei_usb_exit: freeing resources
[09:51:41.523376] [sanei_usb] sanei_usb_exit: freeing device 00
libusb: warning [libusb_exit] device 0.2 still referenced
    0m00.64s real     0m00.01s user     0m00.06s system
#

-- 
Regards,
 Mikolaj

Reply via email to