[sane-devel] Problems with Canon 9000F Mark II

Fri Jul 10 09:18:46 UTC 2015

Dear SANE Developers!

I'm having various problems with the Canon Mark II scanner,
which I bought because it is listed as "fully supported"
on the SANE device list.

The first problem might be distro related (Mageia 5), but
I'll mention it anyway, because it might give some clues:
With the mageia 'scanimage' tool (sane-backends-1.0.24-10.mga5)
I can scan a specific area once, which works perfectly fine,
but when I repeat the very same command, or try a different
scan after that, the scanning process doesn't start and the
command hangs till it times out (which is very long). Once
that happens, I can again scan another image successfully but
after that, it will always hang, and timeout with an error.
I then have to power cycle the scanner to get another image.

[bertl at newhost]$ scanimage -vp -l 100 -t 150 -x 100 -y 2 --format png >out.png
scanimage: scanning image of size 296x8 pixels at 24 bits/pixel
scanimage: acquiring RGB frame
scanimage: min/max graylevel value = 188/246
scanimage: read 7104 bytes in total

[bertl at newhost]$ scanimage -vp -l 100 -t 150 -x 100 -y 2 --format png >out.png
scanimage: scanning image of size 296x8 pixels at 24 bits/pixel
scanimage: acquiring RGB frame
scanimage: min/max graylevel value = 255/0
scanimage: sane_read: Operation was cancelled

[bertl at newhost]$ scanimage -vp -l 100 -t 150 -x 100 -y 2 --format png >out.png
scanimage: scanning image of size 296x8 pixels at 24 bits/pixel
scanimage: acquiring RGB frame
scanimage: min/max graylevel value = 188/247
scanimage: read 7104 bytes in total

[bertl at newhost]$ scanimage -vp -l 100 -t 150 -x 100 -y 2 --format png >out.png
scanimage: scanning image of size 296x8 pixels at 24 bits/pixel
scanimage: acquiring RGB frame
scanimage: min/max graylevel value = 255/0
scanimage: sane_read: Error during device I/O

The second problem is with the scanimage built from the
latest git snapshot to verify if the first problem is
a distribution specific problem.

The scanimage runs fine and seems to retrieve an image,
but then outpus a control character and hangs. When I
interrupt it with CTRL-C, it outputs two more lines
claiming to stop the scanner and hangs again, a second
interrupt finally terminates the scan. Repeating the
command results in a different behaviour.

[bertl at newhost]$ ~/SANE/bin/scanimage -vp -l 100 -t 150 -x 100 -y 2 --format png >out.png
scanimage: scanning image of size 296x16 pixels at 24 bits/pixel
scanimage: acquiring RGB frame
scanimage: min/max graylevel value = 187/254
scanimage: read 14208 bytes in total
<SOH>
<CTRL-C>
scanimage: received signal 2
scanimage: trying to stop scanner
<CTRL-C>
scanimage: received signal 2
scanimage: aborting

[bertl at newhost SANE]$ ~/SANE/bin/scanimage -vp -l 100 -t 150 -x 100 -y 2 --format png >out.png
scanimage: scanning image of size 296x16 pixels at 24 bits/pixel
scanimage: acquiring RGB frame
scanimage: min/max graylevel value = 187/254
scanimage: read 14208 bytes in total
<SOH>
libusb: warning [libusb_close] internal signalling read failed, closing anyway

The final and original problem is with xsane (not sure this 
is the right place here either) which dies a thousand deaths 
when trying to scan - mostly segfaults after the image data
was retrieved or when the scaned image is closed.

Appended are a small bunch of traces acquired during testing.

I would be very hapy to get some hints how to get this
scanner working properly and I'm happy to test/debug
whatever you need to get it done.

Many thanks in advance,
Herbert

Program received signal SIGSEGV, Segmentation fault.
0x00007ffff5c816a6 in __memcpy_avx_unaligned () from /lib64/libc.so.6
Missing separate debuginfos, use: debuginfo-install lib64GConf2_4-3.2.6-8.mga5.x86_64 lib64dbus-glib1_2-0.102-4.mga5.x86_64 lib64dbus1_3-1.8.16-1.mga5.x86_64
(gdb) where
#0  0x00007ffff5c816a6 in __memcpy_avx_unaligned () from /lib64/libc.so.6
#1  0x00000000004339f0 in xsane_viewer_read_image (v=0x10b2610) at xsane-viewer.c:2547
#2  0x000000000043744f in xsane_viewer_new (filename=0x8e7a50 "\360\231}", selection_filetype=0x88a530 "\003", 
    allow_reduction_to_lineart=8225568, output_filename=0x10686b0 "\240\350}", allow_modification=16458496, image_saved=8972480)
    at xsane-viewer.c:3121
#3  0x0000000000464368 in xsane_scan_done (status=SANE_STATUS_EOF) at xsane-scan.c:1226
#4  0x00000000004666d3 in xsane_read_image_data (data=0x7fffdc022000, source=17769312, 
    cond=(GDK_INPUT_WRITE | GDK_INPUT_EXCEPTION | unknown: 92568), cond at entry=GDK_INPUT_READ) at xsane-scan.c:551
#5  0x00007ffff72e4b7f in gdk_io_invoke (source=<optimized out>, condition=<optimized out>, data=0xace8d0) at gdkevents.c:1082
#6  0x00007ffff6daab7d in g_main_dispatch (context=0x6b3800) at gmain.c:3111
#7  g_main_context_dispatch (context=context at entry=0x6b3800) at gmain.c:3710
#8  0x00007ffff6daaf18 in g_main_context_iterate (context=0x6b3800, block=block at entry=1, dispatch=dispatch at entry=1, self=<optimized out>)
    at gmain.c:3781
#9  0x00007ffff6dab232 in g_main_loop_run (loop=0x904bd0) at gmain.c:3975
#10 0x00007ffff769db67 in IA__gtk_main () at gtkmain.c:1268
#11 0x0000000000477bbc in xsane_interface (argv=<optimized out>, argc=<optimized out>) at xsane.c:6210
#12 0x000000000040e56d in main (argc=1, argv=0x7fffffffe0e8) at xsane.c:6410

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7fffe10a9700 (LWP 27171)]
0x00007ffff5bc2a34 in realloc () from /lib64/libc.so.6
(gdb) where
#0  0x00007ffff5bc2a34 in realloc () from /lib64/libc.so.6
#1  0x00007fffe79fbae8 in mp810_fill_buffer (s=0x7ec2b0, ib=0x7fffe10a8c40) at pixma_mp810.c:2176
#2  0x00007fffe79f3fc9 in sanei_pixma_read_image (s=0x7ec2b0, buf=buf at entry=0x7fffdc000f60, len=len at entry=107535) at pixma_common.c:917
#3  0x00007fffe79ef95f in reader_loop (ss=0x867a10) at pixma.c:1019
#4  0x00007fffe79efb35 in reader_thread (arg=0x867a10) at pixma.c:1076
#5  0x00007ffff7bbe16e in local_thread (arg=0x7ffff7ddbf20 <td>) at sanei_thread.c:355
#6  0x00007ffff5eff5bd in start_thread () from /lib64/libpthread.so.0
#7  0x00007ffff5c3c5cd in clone () from /lib64/libc.so.6

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7fffe10a9700 (LWP 27584)]
0x00007ffff5bbec70 in _int_free () from /lib64/libc.so.6
(gdb) where
#0  0x00007ffff5bbec70 in _int_free () from /lib64/libc.so.6
#1  0x00007ffff5bc2828 in free () from /lib64/libc.so.6
#2  0x00007ffff552ba38 in handle_bulk_completion (urb=<optimized out>, itransfer=<optimized out>) at os/linux_usbfs.c:2338
#3  reap_for_handle (handle=<optimized out>) at os/linux_usbfs.c:2561
#4  op_handle_events (ctx=0xdd4de991e27ed6e2, fds=0x7fffdc03b740, nfds=140736884619136, num_ready=-179112056) at os/linux_usbfs.c:2613
#5  0x00007ffff5525e43 in handle_events (ctx=ctx at entry=0x82b920, tv=tv at entry=0x7fffe10a8980) at io.c:2089
#6  0x00007ffff5526a53 in libusb_handle_events_timeout_completed (ctx=ctx at entry=0x82b920, tv=tv at entry=0x7fffe10a89c0, 
    completed=completed at entry=0x7fffe10a8a1c) at io.c:2174
#7  0x00007ffff5526b50 in libusb_handle_events_completed (ctx=ctx at entry=0x82b920, completed=completed at entry=0x7fffe10a8a1c) at io.c:2273
#8  0x00007ffff55273b1 in sync_transfer_wait_for_completion (transfer=transfer at entry=0x7fffdc03b6e0) at sync.c:50
#9  0x00007ffff5527489 in do_sync_bulk_transfer (dev_handle=0x7f1ff0, endpoint=<optimized out>, 
#10 0x00007ffff552781f in libusb_bulk_transfer (dev_handle=<optimized out>, endpoint=<optimized out>, 
#11 0x00007ffff7bb920e in sanei_usb_read_bulk (dn=<optimized out>, 
#12 0x00007fffe79f2df3 in sanei_pixma_read (io=0x7ebfa0, buf=buf at entry=0x7fffdbfad218, size=size at entry=523792) at pixma_io_sanei.c:544
#13 0x00007fffe79fb637 in read_image_block (data=<optimized out>, header=0x7fffe10a8bd0 "\006\006", s=0x7ec2b0) at pixma_mp810.c:1044
#14 mp810_fill_buffer (s=0x7ec2b0, ib=0x7fffe10a8c40) at pixma_mp810.c:2196
#15 0x00007fffe79f3fc9 in sanei_pixma_read_image (s=0x7ec2b0, buf=buf at entry=0x7fffdc000f60, len=len at entry=239382) at pixma_common.c:917
#16 0x00007fffe79ef95f in reader_loop (ss=0x8679d0) at pixma.c:1019
#17 0x00007fffe79efb35 in reader_thread (arg=0x8679d0) at pixma.c:1076
#18 0x00007ffff7bbe16e in local_thread (arg=0x7ffff7ddbf20 <td>) at sanei_thread.c:355
#19 0x00007ffff5eff5bd in start_thread () from /lib64/libpthread.so.0
#20 0x00007ffff5c3c5cd in clone () from /lib64/libc.so.6

*** Error in `/usr/bin/xsane': realloc(): invalid old size: 0x00007fffd472e010 ***
======= Backtrace: =========
/lib64/libc.so.6(+0x7241e)[0x7ffff5bb741e]
/lib64/libc.so.6(+0x7cba0)[0x7ffff5bc1ba0]
/lib64/libc.so.6(realloc+0xee)[0x7ffff5bc2a7e]
/usr/lib64/sane/libsane-pixma.so.1(+0x19ae8)[0x7fffe79fbae8]
/usr/lib64/sane/libsane-pixma.so.1(sanei_pixma_read_image+0x99)[0x7fffe79f3fc9]
/usr/lib64/sane/libsane-pixma.so.1(+0xd95f)[0x7fffe79ef95f]
/usr/lib64/sane/libsane-pixma.so.1(+0xdb35)[0x7fffe79efb35]
/lib64/libsane.so.1(+0x1016e)[0x7ffff7bbe16e]
/lib64/libpthread.so.0(+0x75bd)[0x7ffff5eff5bd]
/lib64/libc.so.6(clone+0x6d)[0x7ffff5c3c5cd]

*** Error in `/usr/bin/xsane': munmap_chunk(): invalid pointer: 0x00007fffd8236010 ***
======= Backtrace: =========
/lib64/libc.so.6(+0x7241e)[0x7ffff5bb741e]
/lib64/libc.so.6(cfree+0x189)[0x7ffff5bc2969]
/usr/lib64/sane/libsane-pixma.so.1(+0x1757b)[0x7fffe79f957b]
/usr/lib64/sane/libsane-pixma.so.1(sanei_pixma_close+0x9a)[0x7fffe79f3d3a]
/usr/lib64/sane/libsane-pixma.so.1(sane_pixma_close+0x54)[0x7fffe79f13a4]
/lib64/libsane.so.1(sane_dll_close+0x24)[0x7ffff7bcb034]
/usr/bin/xsane[0x46a960]
/usr/bin/xsane[0x47333f]
/lib64/libgobject-2.0.so.0(g_closure_invoke+0x145)[0x7ffff707f0e5]
/lib64/libgobject-2.0.so.0(+0x2175c)[0x7ffff709075c]
/lib64/libgobject-2.0.so.0(g_signal_emit_valist+0xf6c)[0x7ffff7098e4c]
/lib64/libgobject-2.0.so.0(g_signal_emit+0x82)[0x7ffff7099082]
/lib64/libgtk-x11-2.0.so.0(gtk_widget_activate+0x76)[0x7ffff77af336]
/lib64/libgtk-x11-2.0.so.0(gtk_menu_shell_activate_item+0xfd)[0x7ffff76b18bd]
/lib64/libgtk-x11-2.0.so.0(+0x13dc3b)[0x7ffff76b1c3b]
/lib64/libgtk-x11-2.0.so.0(+0x12bfbf)[0x7ffff769ffbf]
/lib64/libgobject-2.0.so.0(g_closure_invoke+0x145)[0x7ffff707f0e5]
/lib64/libgobject-2.0.so.0(+0x21652)[0x7ffff7090652]
/lib64/libgobject-2.0.so.0(g_signal_emit_valist+0xaa0)[0x7ffff7098980]
/lib64/libgobject-2.0.so.0(g_signal_emit+0x82)[0x7ffff7099082]
/lib64/libgtk-x11-2.0.so.0(+0x23c4fc)[0x7ffff77b04fc]
/lib64/libgtk-x11-2.0.so.0(gtk_propagate_event+0xc4)[0x7ffff769e714]
/lib64/libgtk-x11-2.0.so.0(gtk_main_do_event+0x38b)[0x7ffff769eb8b]
/lib64/libgdk-x11-2.0.so.0(+0x598bc)[0x7ffff73198bc]
/lib64/libglib-2.0.so.0(g_main_context_dispatch+0x22d)[0x7ffff6daac6d]
/lib64/libglib-2.0.so.0(+0x48f18)[0x7ffff6daaf18]
/lib64/libglib-2.0.so.0(g_main_loop_run+0xc2)[0x7ffff6dab232]
/lib64/libgtk-x11-2.0.so.0(gtk_main+0xa7)[0x7ffff769db67]
/usr/bin/xsane[0x477bbc]
/usr/bin/xsane(main+0x48d)[0x40e56d]
/lib64/libc.so.6(__libc_start_main+0xf0)[0x7ffff5b64fd0]
/usr/bin/xsane[0x40e633]