[sane-devel] canon dr-7550c batch scan only scans single page

[Jurriaan]

I have recently bought a uses Canon DR-7550c scanner for a non-profit
organisation. It scans, but it doesn't scan multiple pages.

output of

SANE_DEBUG_CANON_DR=15 scanimage -v --mode=Gray --batch --batch-count
999 --format=tiff -y 297 --page-height 297 --resolution 200
'--source=ADF Duplex' 

below.

The interesting part is 

Scanned page 2. (scanner status = 5)
Scanning page 3
[15:37:33.785430] [canon_dr] sane_start: start
[15:37:33.785448] [canon_dr] started=1, side=1, source=3
[15:37:33.785461] [canon_dr] update_i_params: start
[15:37:33.785474] [canon_dr] update_i_params: finish
[15:37:33.785486] [canon_dr] clean_params: start
[15:37:33.785498] [canon_dr] clean_params: finish
[15:37:33.785511] [canon_dr] object_position: start
[15:37:33.785523] [canon_dr] object_position: load
[15:37:33.785536] [canon_dr] do_usb_cmd: start 1618234653 785535
[15:37:33.793366] [canon_dr] stat: clearing error 'Error during device I/O'
[15:37:33.793414] [canon_dr] do_usb_clear: start
[15:37:33.893510] [canon_dr] do_usb_clear: clear halt
[15:37:33.894486] [canon_dr] do_usb_cmd: start 1618234653 894484
[15:37:33.896116] [canon_dr] do_usb_cmd: finish 1618234653 896115
[15:37:33.896141] [canon_dr] sense_handler: start
[15:37:33.896154] [canon_dr] Sense=0x5, ASC=0x3a, ASCQ=00, EOM=0, ILI=0, info=00000000
[15:37:33.896170] [canon_dr] Illegal request: no paper
[15:37:33.896182] [canon_dr] do_usb_clear: finish after RS
[15:37:33.896195] [canon_dr] stat: bad RS status, 7
[15:37:33.896209] [canon_dr] sane_start: ERROR: cannot load page
[15:37:33.896222] [canon_dr] sane_start: error 7
scanimage: sane_start: Document feeder out of documents

I think. Could anyone give me hints on what to try next? Other options,
higher level of debugging, install development-version of sane?

Thanks,
Jurriaan

[15:37:26.088273] [sanei_debug] Setting debug level of canon_dr to 15.
[15:37:26.088404] [canon_dr] sane_init: start
[15:37:26.088423] [canon_dr] sane_init: canon_dr backend 1.0.58, from sane-backends 1.0.29
[15:37:26.088436] [canon_dr] sane_init: finish
[15:37:26.088449] [canon_dr] sane_get_devices: start
[15:37:26.199669] [canon_dr] sane_get_devices: reading config file canon_dr.conf
[15:37:26.199821] [canon_dr] sane_get_devices: looking for 'scsi CANON CR'
[15:37:26.200104] [canon_dr] sane_get_devices: looking for 'scsi CANON DR'
[15:37:26.200329] [canon_dr] sane_get_devices: setting "duplex-offset" to 840
[15:37:26.200347] [canon_dr] sane_get_devices: setting "vendor-name" to CANON
[15:37:26.200360] [canon_dr] sane_get_devices: setting "model-name" to DR-2080C
[15:37:26.200374] [canon_dr] sane_get_devices: setting "version-name" to XXXX
[15:37:26.200387] [canon_dr] sane_get_devices: setting "padded-read" to 1
[15:37:26.200400] [canon_dr] sane_get_devices: looking for 'usb 0x04a9 0x1601'
[15:37:26.200414] [canon_dr] sane_get_devices: looking for 'usb 0x04a9 0x1602'
[15:37:26.200428] [canon_dr] sane_get_devices: looking for 'usb 0x04a9 0x1603'
[15:37:26.200441] [canon_dr] sane_get_devices: looking for 'usb 0x04a9 0x1604'
[15:37:26.200455] [canon_dr] sane_get_devices: looking for 'usb 0x04a9 0x1606'
[15:37:26.200468] [canon_dr] sane_get_devices: looking for 'usb 0x04a9 0x1607'
[15:37:26.200482] [canon_dr] sane_get_devices: setting "duplex-offset" to 432
[15:37:26.200494] [canon_dr] sane_get_devices: looking for 'usb 0x04a9 0x1608'
[15:37:26.200508] [canon_dr] sane_get_devices: setting "padded-read" to 1
[15:37:26.200521] [canon_dr] sane_get_devices: looking for 'usb 0x04a9 0x1609'
[15:37:26.200535] [canon_dr] sane_get_devices: setting "duplex-offset" to 840
[15:37:26.200547] [canon_dr] sane_get_devices: setting "vendor-name" to CANON
[15:37:26.200560] [canon_dr] sane_get_devices: setting "model-name" to DR-2050C
[15:37:26.200573] [canon_dr] sane_get_devices: setting "version-name" to XXXX
[15:37:26.200586] [canon_dr] sane_get_devices: setting "padded-read" to 1
[15:37:26.200599] [canon_dr] sane_get_devices: looking for 'usb 0x04a9 0x160a'
[15:37:26.200612] [canon_dr] sane_get_devices: looking for 'usb 0x04a9 0x160b'
[15:37:26.200625] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x160c'
[15:37:26.200639] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x160f'
[15:37:26.200651] [canon_dr] sane_get_devices: looking for 'usb 0x04a9 0x2222'
[15:37:26.200665] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x1614'
[15:37:26.200678] [canon_dr] sane_get_devices: setting "duplex-offset" to 400
[15:37:26.200691] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x1617'
[15:37:26.200704] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x1618'
[15:37:26.200718] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x161a'
[15:37:26.200731] [canon_dr] sane_get_devices: setting "duplex-offset" to 400
[15:37:26.200743] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x161b'
[15:37:26.200757] [canon_dr] sane_get_devices: setting "duplex-offset" to 400
[15:37:26.200769] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x161d'
[15:37:26.200783] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x1620'
[15:37:26.200796] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x1622'
[15:37:26.200809] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x1623'
[15:37:26.200822] [canon_dr] attach_one: start
[15:37:26.200833] [canon_dr] attach_one: looking for 'libusb:001:003'
[15:37:26.200847] [canon_dr] connect_fd: start
[15:37:26.200860] [canon_dr] connect_fd: opening USB device (libusb:001:003)
[15:37:26.201875] [canon_dr] wait_scanner: start
[15:37:26.201902] [canon_dr] do_usb_cmd: start 1618234646 201901
[15:37:26.202883] [canon_dr] do_usb_cmd: finish 1618234646 202882
[15:37:26.202907] [canon_dr] wait_scanner: finish (status=0)
[15:37:26.202921] [canon_dr] connect_fd: finish
[15:37:26.202933] [canon_dr] init_inquire: start
[15:37:26.202945] [canon_dr] do_usb_cmd: start 1618234646 202944
[15:37:26.205755] [canon_dr] do_usb_cmd: finish 1618234646 205754
[15:37:26.205813] [canon_dr] init_inquire: Found CANON scanner DR-7550C version 1.13 at libusb:001:003
[15:37:26.205828] [canon_dr] init_inquire: finish
[15:37:26.205840] [canon_dr] init_vpd: start
[15:37:26.205852] [canon_dr] do_usb_cmd: start 1618234646 205851
[15:37:26.209504] [canon_dr] do_usb_cmd: finish 1618234646 209502
[15:37:26.209530] [canon_dr] init_vpd: length=2b
[15:37:26.209543] [canon_dr] standard options
[15:37:26.209555] [canon_dr]   basic x res: 600 dpi
[15:37:26.209568] [canon_dr]   basic y res: 600 dpi
[15:37:26.209580] [canon_dr]   step x res: 0 dpi
[15:37:26.209592] [canon_dr]   step y res: 0 dpi
[15:37:26.209605] [canon_dr]   max x res: 600 dpi
[15:37:26.209617] [canon_dr]   max y res: 600 dpi
[15:37:26.209629] [canon_dr]   min x res: 100 dpi
[15:37:26.209642] [canon_dr]   min y res: 100 dpi
[15:37:26.209654] [canon_dr]   60 dpi: 0
[15:37:26.209666] [canon_dr]   75 dpi: 0
[15:37:26.209678] [canon_dr]   100 dpi: 0
[15:37:26.209691] [canon_dr]   120 dpi: 0
[15:37:26.209703] [canon_dr]   150 dpi: 0
[15:37:26.209715] [canon_dr]   160 dpi: 0
[15:37:26.209741] [canon_dr]   180 dpi: 0
[15:37:26.209754] [canon_dr]   200 dpi: 0
[15:37:26.209767] [canon_dr]   240 dpi: 0
[15:37:26.209779] [canon_dr]   300 dpi: 0
[15:37:26.209791] [canon_dr]   320 dpi: 0
[15:37:26.209803] [canon_dr]   400 dpi: 0
[15:37:26.209814] [canon_dr]   480 dpi: 0
[15:37:26.209826] [canon_dr]   600 dpi: 0
[15:37:26.209839] [canon_dr]   800 dpi: 0
[15:37:26.209851] [canon_dr]   1200 dpi: 0
[15:37:26.209863] [canon_dr]   max width: 14784 (12.32 in)
[15:37:26.209884] [canon_dr]   max length: 20400 (17.00 in)
[15:37:26.209898] [canon_dr]   AWD: 0
[15:37:26.209911] [canon_dr]   CE Emphasis: 0
[15:37:26.209923] [canon_dr]   C Emphasis: 0
[15:37:26.209935] [canon_dr]   High quality: 0
[15:37:26.209947] [canon_dr]   grayscale: 1
[15:37:26.209959] [canon_dr]   halftone: 1
[15:37:26.209971] [canon_dr]   monochrome: 1
[15:37:26.209983] [canon_dr]   overflow: 1
[15:37:26.209995] [canon_dr] init_vpd: finish
[15:37:26.210007] [canon_dr] init_model: start
[15:37:26.210020] [canon_dr] init_model: finish
[15:37:26.210032] [canon_dr] init_panel: start
[15:37:26.210044] [canon_dr] read_panel: start 0
[15:37:26.210056] [canon_dr] read_panel: running
[15:37:26.210068] [canon_dr] do_usb_cmd: start 1618234646 210068
[15:37:26.211884] [canon_dr] do_usb_cmd: finish 1618234646 211883
[15:37:26.211907] [canon_dr] read_panel: finish 1
[15:37:26.211921] [canon_dr] send_panel: start
[15:37:26.211933] [canon_dr] do_usb_cmd: start 1618234646 211933
[15:37:26.215508] [canon_dr] do_usb_cmd: finish 1618234646 215506
[15:37:26.215534] [canon_dr] send_panel: finish 0
[15:37:26.215547] [canon_dr] init_panel: finish
[15:37:26.215559] [canon_dr] init_user: start
[15:37:26.215571] [canon_dr] init_user: finish
[15:37:26.215583] [canon_dr] init_options: start
[15:37:26.215595] [canon_dr] init_options: finish
[15:37:26.215607] [canon_dr] disconnect_fd: start
[15:37:26.215624] [canon_dr] disconnecting usb device
[15:37:26.215678] [canon_dr] disconnect_fd: finish
[15:37:26.215693] [canon_dr] attach_one: finish
[15:37:26.215709] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x1624'
[15:37:26.215724] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x1626'
[15:37:26.215743] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x162b'
[15:37:26.215757] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x162c'
[15:37:26.215770] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x1638'
[15:37:26.215784] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x1639'
[15:37:26.215797] [canon_dr] sane_get_devices: setting "extra-status" to 1
[15:37:26.215810] [canon_dr] sane_get_devices: setting "duplex-offset" to 400
[15:37:26.215823] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x163e'
[15:37:26.215836] [canon_dr] sane_get_devices: setting "extra-status" to 1
[15:37:26.215849] [canon_dr] sane_get_devices: setting "duplex-offset" to 400
[15:37:26.215865] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x163f'
[15:37:26.215879] [canon_dr] sane_get_devices: setting "duplex-offset" to 400
[15:37:26.215906] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x1640'
[15:37:26.215920] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x1641'
[15:37:26.215933] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x1646'
[15:37:26.215947] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x1648'
[15:37:26.215960] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x164a'
[15:37:26.215973] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x164b'
[15:37:26.215987] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x164c'
[15:37:26.216000] [canon_dr] sane_get_devices: config option "buffer-size" (8000000) is > 2097152, scanning problems may result
[15:37:26.216013] [canon_dr] sane_get_devices: setting "buffer-size" to 8000000
[15:37:26.216025] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x164f'
[15:37:26.216039] [canon_dr] sane_get_devices: config option "buffer-size" (8000000) is > 2097152, scanning problems may result
[15:37:26.216051] [canon_dr] sane_get_devices: setting "buffer-size" to 8000000
[15:37:26.216063] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x1650'
[15:37:26.216077] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x1651'
[15:37:26.216090] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x1652'
[15:37:26.216103] [canon_dr] sane_get_devices: setting "duplex-offset" to 1640
[15:37:26.216115] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x1654'
[15:37:26.216129] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x1657'
[15:37:26.216142] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x1658'
[15:37:26.216154] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x1659'
[15:37:26.216168] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x165b'
[15:37:26.216181] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x165d'
[15:37:26.216194] [canon_dr] sane_get_devices: looking for 'usb 0x1083 0x165f'
[15:37:26.216216] [canon_dr] sane_get_devices: found scanner libusb:001:003
[15:37:26.216230] [canon_dr] sane_get_devices: found 1 scanner(s)
[15:37:26.216243] [canon_dr] sane_get_devices: finish
[15:37:28.128796] [canon_dr] sane_open: start
[15:37:28.128865] [canon_dr] sane_open: searching currently attached scanners
[15:37:28.128879] [canon_dr] sane_open: device libusb:001:003 requested
[15:37:28.128890] [canon_dr] sane_open: device libusb:001:003 found
[15:37:28.128901] [canon_dr] connect_fd: start
[15:37:28.128913] [canon_dr] connect_fd: opening USB device (libusb:001:003)
[15:37:28.129875] [canon_dr] wait_scanner: start
[15:37:28.129908] [canon_dr] do_usb_cmd: start 1618234648 129907
[15:37:28.130881] [canon_dr] do_usb_cmd: finish 1618234648 130880
[15:37:28.130905] [canon_dr] wait_scanner: finish (status=0)
[15:37:28.130918] [canon_dr] connect_fd: finish
[15:37:28.130931] [canon_dr] sane_open: finish
scanimage: rounded value of page-height from 297 to 296.994
scanimage: rounded value of br-y from 297 to 296.994
Scanning 999 pages, incrementing by 1, numbering from 1
Scanning page 1
[15:37:28.131072] [canon_dr] sane_start: start
[15:37:28.131087] [canon_dr] started=0, side=0, source=3
[15:37:28.131100] [canon_dr] object_position: start
[15:37:28.131112] [canon_dr] object_position: eject
[15:37:28.131124] [canon_dr] do_usb_cmd: start 1618234648 131123
[15:37:28.133507] [canon_dr] do_usb_cmd: finish 1618234648 133505
[15:37:28.133533] [canon_dr] object_position: finish
[15:37:28.133546] [canon_dr] wait_scanner: start
[15:37:28.133557] [canon_dr] do_usb_cmd: start 1618234648 133557
[15:37:28.135633] [canon_dr] do_usb_cmd: finish 1618234648 135631
[15:37:28.135660] [canon_dr] wait_scanner: finish (status=0)
[15:37:28.135674] [canon_dr] load_lut: start 0 0
[15:37:28.135718] [canon_dr] load_lut: 
[15:37:28.135742] [canon_dr] 000: 00 01 02 03 04 05 06 07 08 09 0a 0b 0c 0d 0e 0f ................
[15:37:28.135760] [canon_dr] 010: 10 11 12 13 14 15 16 17 18 19 1a 1b 1c 1d 1e 1f ................
[15:37:28.135776] [canon_dr] 020: 20 21 22 23 24 25 26 27 28 29 2a 2b 2c 2d 2e 2f  !"#$%&'()*+,-./
[15:37:28.135816] [canon_dr] 030: 30 31 32 33 34 35 36 37 38 39 3a 3b 3c 3d 3e 3f 0123456789:;<=>?
[15:37:28.135835] [canon_dr] 040: 40 41 42 43 44 45 46 47 48 49 4a 4b 4c 4d 4e 4f @ABCDEFGHIJKLMNO
[15:37:28.135852] [canon_dr] 050: 50 51 52 53 54 55 56 57 58 59 5a 5b 5c 5d 5e 5f PQRSTUVWXYZ[\]^_
[15:37:28.135868] [canon_dr] 060: 60 61 62 63 64 65 66 67 68 69 6a 6b 6c 6d 6e 6f `abcdefghijklmno
[15:37:28.135885] [canon_dr] 070: 70 71 72 73 74 75 76 77 78 79 7a 7b 7c 7d 7e 7f pqrstuvwxyz{|}~.
[15:37:28.135902] [canon_dr] 080: 80 81 82 83 84 85 86 87 88 89 8a 8b 8c 8d 8e 8f ................
[15:37:28.135919] [canon_dr] 090: 90 91 92 93 94 95 96 97 98 99 9a 9b 9c 9d 9e 9f ................
[15:37:28.135936] [canon_dr] 0a0: a0 a1 a2 a3 a4 a5 a6 a7 a8 a9 aa ab ac ad ae af ................
[15:37:28.135952] [canon_dr] 0b0: b0 b1 b2 b3 b4 b5 b6 b7 b8 b9 ba bb bc bd be bf ................
[15:37:28.135969] [canon_dr] 0c0: c0 c1 c2 c3 c4 c5 c6 c7 c8 c9 ca cb cc cd ce cf ................
[15:37:28.135986] [canon_dr] 0d0: d0 d1 d2 d3 d4 d5 d6 d7 d8 d9 da db dc dd de df ................
[15:37:28.136002] [canon_dr] 0e0: e0 e1 e2 e3 e4 e5 e6 e7 e8 e9 ea eb ec ed ee ef ................
[15:37:28.136019] [canon_dr] 0f0: f0 f1 f2 f3 f4 f5 f6 f7 f8 f9 fa fb fc fd fe ff ................
[15:37:28.136031] [canon_dr] load_lut: finish
[15:37:28.136043] [canon_dr] calibrate_AFE: start
[15:37:28.136055] [canon_dr] calibrate_AFE: not required
[15:37:28.136067] [canon_dr] calibrate_fine: start
[15:37:28.136079] [canon_dr] calibrate_fine: not required
[15:37:28.136091] [canon_dr] calibrate_fine_buffer: start
[15:37:28.136103] [canon_dr] calibrate_fine_buffer: not required
[15:37:28.136115] [canon_dr] send_panel: start
[15:37:28.136128] [canon_dr] do_usb_cmd: start 1618234648 136127
[15:37:28.138503] [canon_dr] do_usb_cmd: finish 1618234648 138501
[15:37:28.138531] [canon_dr] send_panel: finish 0
[15:37:28.138544] [canon_dr] update_params: start
[15:37:28.138557] [canon_dr] update_params: user params: w:1700 h:2338 m:2 f:0 b:8
[15:37:28.138570] [canon_dr] update_params: user params: B:1700 vB:1700 vw:1700
[15:37:28.138582] [canon_dr] update_params: user params: x b:10200 t:0 d:200 y b:14033 t:0 d:200
[15:37:28.138596] [canon_dr] update_params: scan params: w:1700 h:2338 m:2 f:0 b:8
[15:37:28.138609] [canon_dr] update_params: scan params: B:1700 vB:1700 vw:1700
[15:37:28.138622] [canon_dr] update_params: scan params: x b:10200 t:0 d:200 y b:14033 t:0 d:200
[15:37:28.138635] [canon_dr] update_params: i params: w:1700 h:2338 m:2 f:0 b:8
[15:37:28.138647] [canon_dr] update_params: i params: B:1700 vB:1700 vw:1700
[15:37:28.138659] [canon_dr] update_params: i params: x b:10200 t:0 d:200 y b:14033 t:0 d:200
[15:37:28.138672] [canon_dr] update_params: finish
[15:37:28.138684] [canon_dr] set_window: start
[15:37:28.138697] [canon_dr] do_usb_cmd: start 1618234648 138696
[15:37:28.142631] [canon_dr] do_usb_cmd: finish 1618234648 142629
[15:37:28.142662] [canon_dr] do_usb_cmd: start 1618234648 142662
[15:37:28.146507] [canon_dr] do_usb_cmd: finish 1618234648 146505
[15:37:28.146535] [canon_dr] set_window: finish
[15:37:28.146548] [canon_dr] ssm_buffer: start
[15:37:28.146561] [canon_dr] do_usb_cmd: start 1618234648 146560
[15:37:28.149378] [canon_dr] do_usb_cmd: finish 1618234648 149377
[15:37:28.149403] [canon_dr] ssm_buffer: finish
[15:37:28.149416] [canon_dr] ssm_do: start
[15:37:28.149428] [canon_dr] do_usb_cmd: start 1618234648 149428
[15:37:28.152128] [canon_dr] do_usb_cmd: finish 1618234648 152127
[15:37:28.152156] [canon_dr] do_usb_cmd: start 1618234648 152155
[15:37:28.155504] [canon_dr] do_usb_cmd: finish 1618234648 155503
[15:37:28.155530] [canon_dr] ssm_do: finish
[15:37:28.155543] [canon_dr] ssm_df: start
[15:37:28.155556] [canon_dr] do_usb_cmd: start 1618234648 155555
[15:37:28.158755] [canon_dr] do_usb_cmd: finish 1618234648 158753
[15:37:28.158784] [canon_dr] ssm_df: finish
[15:37:28.158797] [canon_dr] ssm2_hw_enhancement: start
[15:37:28.158809] [canon_dr] do_usb_cmd: start 1618234648 158809
[15:37:28.162128] [canon_dr] do_usb_cmd: finish 1618234648 162126
[15:37:28.162185] [canon_dr] ssm2_hw_enhancement: finish
[15:37:28.162198] [canon_dr] clean_params: start
[15:37:28.162209] [canon_dr] clean_params: finish
[15:37:28.162220] [canon_dr] image_buffers: start
[15:37:28.162288] [canon_dr] image_buffers: finish
[15:37:28.162307] [canon_dr] load_lut: start 0 0
[15:37:28.162323] [canon_dr] load_lut: 
[15:37:28.162344] [canon_dr] 000: 00 01 02 03 04 05 06 07 08 09 0a 0b 0c 0d 0e 0f ................
[15:37:28.162362] [canon_dr] 010: 10 11 12 13 14 15 16 17 18 19 1a 1b 1c 1d 1e 1f ................
[15:37:28.162378] [canon_dr] 020: 20 21 22 23 24 25 26 27 28 29 2a 2b 2c 2d 2e 2f  !"#$%&'()*+,-./
[15:37:28.162395] [canon_dr] 030: 30 31 32 33 34 35 36 37 38 39 3a 3b 3c 3d 3e 3f 0123456789:;<=>?
[15:37:28.162412] [canon_dr] 040: 40 41 42 43 44 45 46 47 48 49 4a 4b 4c 4d 4e 4f @ABCDEFGHIJKLMNO
[15:37:28.162428] [canon_dr] 050: 50 51 52 53 54 55 56 57 58 59 5a 5b 5c 5d 5e 5f PQRSTUVWXYZ[\]^_
[15:37:28.162445] [canon_dr] 060: 60 61 62 63 64 65 66 67 68 69 6a 6b 6c 6d 6e 6f `abcdefghijklmno
[15:37:28.162462] [canon_dr] 070: 70 71 72 73 74 75 76 77 78 79 7a 7b 7c 7d 7e 7f pqrstuvwxyz{|}~.
[15:37:28.162479] [canon_dr] 080: 80 81 82 83 84 85 86 87 88 89 8a 8b 8c 8d 8e 8f ................
[15:37:28.162496] [canon_dr] 090: 90 91 92 93 94 95 96 97 98 99 9a 9b 9c 9d 9e 9f ................
[15:37:28.162512] [canon_dr] 0a0: a0 a1 a2 a3 a4 a5 a6 a7 a8 a9 aa ab ac ad ae af ................
[15:37:28.162529] [canon_dr] 0b0: b0 b1 b2 b3 b4 b5 b6 b7 b8 b9 ba bb bc bd be bf ................
[15:37:28.162545] [canon_dr] 0c0: c0 c1 c2 c3 c4 c5 c6 c7 c8 c9 ca cb cc cd ce cf ................
[15:37:28.162562] [canon_dr] 0d0: d0 d1 d2 d3 d4 d5 d6 d7 d8 d9 da db dc dd de df ................
[15:37:28.162579] [canon_dr] 0e0: e0 e1 e2 e3 e4 e5 e6 e7 e8 e9 ea eb ec ed ee ef ................
[15:37:28.162595] [canon_dr] 0f0: f0 f1 f2 f3 f4 f5 f6 f7 f8 f9 fa fb fc fd fe ff ................
[15:37:28.162608] [canon_dr] load_lut: finish
[15:37:28.162620] [canon_dr] object_position: start
[15:37:28.162632] [canon_dr] object_position: load
[15:37:28.162645] [canon_dr] do_usb_cmd: start 1618234648 162644
[15:37:28.191050] [canon_dr] do_usb_cmd: finish 1618234648 191046
[15:37:28.191132] [canon_dr] object_position: finish
[15:37:28.191146] [canon_dr] wait_scanner: start
[15:37:28.191158] [canon_dr] do_usb_cmd: start 1618234648 191158
[15:37:28.192881] [canon_dr] do_usb_cmd: finish 1618234648 192879
[15:37:28.192905] [canon_dr] wait_scanner: finish (status=0)
[15:37:28.192919] [canon_dr] start_scan: start
[15:37:28.192932] [canon_dr] do_usb_cmd: start 1618234648 192931
[15:37:31.411191] [canon_dr] do_usb_cmd: finish 1618234651 411184
[15:37:31.411282] [canon_dr] start_scan: finish
[15:37:31.411295] [canon_dr] get_pixelsize: start
[15:37:31.411308] [canon_dr] get_pixelsize: unneeded, finishing
[15:37:31.411321] [canon_dr] started=1, side=0, source=3
[15:37:31.411334] [canon_dr] check_for_cancel: start
[15:37:31.411347] [canon_dr] check_for_cancel: finish 0
[15:37:31.411360] [canon_dr] sane_start: finish 0
[15:37:31.411467] [canon_dr] sane_get_parameters: start
[15:37:31.411483] [canon_dr] sane_get_parameters: x: max=14784, page=10200, gpw=10200, res=200
[15:37:31.411497] [canon_dr] sane_get_parameters: y: max=20400, page=14033, gph=14033, res=200
[15:37:31.411510] [canon_dr] sane_get_parameters: area: tlx=0, brx=10200, tly=0, bry=14033
[15:37:31.411522] [canon_dr] sane_get_parameters: params: ppl=1700, Bpl=1700, lines=2338
[15:37:31.411535] [canon_dr] sane_get_parameters: params: format=0, depth=8, last=1
[15:37:31.411547] [canon_dr] sane_get_parameters: finish
scanimage: scanning image of size 1700x2338 pixels at 8 bits/pixel
scanimage: acquiring gray frame
[15:37:31.411586] [canon_dr] sane_read: start
[15:37:31.411601] [canon_dr] read_from_scanner: start
[15:37:31.411613] [canon_dr] read_from_scanner: si:0 to:3974600 rx:0 re:3974600 bu:2097152 pa:2096100 ex:0
[15:37:31.411673] [canon_dr] do_usb_cmd: start 1618234651 411672
[15:37:32.992586] [canon_dr] do_usb_cmd: finish 1618234652 992579
[15:37:32.992698] [canon_dr] read_from_scanner: got GOOD, returning GOOD 2096100
[15:37:32.992713] [canon_dr] copy_simplex: per-line copy
[15:37:32.994179] [canon_dr] copy_simplex: finished
[15:37:32.994441] [canon_dr] read_from_scanner: sto:3974600 srx:2096100 sef:0 uto:3974600 urx:0 uef:0
[15:37:32.994464] [canon_dr] read_from_scanner: finish
[15:37:32.994476] [canon_dr] read_from_buffer: start
[15:37:32.994488] [canon_dr] read_from_buffer: si:0 to:3974600 tx:0 bu:32768 pa:32768
[15:37:32.994519] [canon_dr] read_from_buffer: finished
[15:37:32.994534] [canon_dr] check_for_cancel: start
[15:37:32.994546] [canon_dr] check_for_cancel: finish 0
[15:37:32.994559] [canon_dr] sane_read: finish 0
[15:37:32.994690] [canon_dr] sane_read: start
[15:37:32.994707] [canon_dr] read_from_scanner: start
[15:37:32.994719] [canon_dr] read_from_scanner: si:0 to:3974600 rx:2096100 re:1878500 bu:2097152 pa:2096100 ex:0
[15:37:32.994747] [canon_dr] do_usb_cmd: start 1618234652 994747
[15:37:33.298998] [canon_dr] stat: status 2
[15:37:33.299082] [canon_dr] do_usb_clear: start
[15:37:33.399177] [canon_dr] do_usb_cmd: start 1618234653 399168
[15:37:33.400117] [canon_dr] do_usb_cmd: finish 1618234653 400116
[15:37:33.400141] [canon_dr] sense_handler: start
[15:37:33.400155] [canon_dr] Sense=00, ASC=00, ASCQ=00, EOM=0, ILI=1, info=0x035200
[15:37:33.400171] [canon_dr] No sense: EOM remainder:217600
[15:37:33.400183] [canon_dr] do_usb_clear: finish after RS
[15:37:33.400195] [canon_dr] in: short read, 2096100/1878500
[15:37:33.401908] [canon_dr] do_usb_cmd: finish 1618234653 401906
[15:37:33.401933] [canon_dr] read_from_scanner: got EOF, finishing 1878500
[15:37:33.401947] [canon_dr] copy_simplex: per-line copy
[15:37:33.403596] [canon_dr] copy_simplex: finished
[15:37:33.404151] [canon_dr] read_from_scanner: sto:3974600 srx:3974600 sef:1 uto:3974600 urx:32768 uef:0
[15:37:33.404174] [canon_dr] read_from_scanner: finish
[15:37:33.404187] [canon_dr] sane_read: side 0 counter 1
[15:37:33.404200] [canon_dr] read_from_buffer: start
[15:37:33.404212] [canon_dr] read_from_buffer: si:0 to:3974600 tx:32768 bu:32768 pa:32768
[15:37:33.404236] [canon_dr] read_from_buffer: finished
[15:37:33.404249] [canon_dr] check_for_cancel: start
[15:37:33.404262] [canon_dr] check_for_cancel: finish 0
[15:37:33.404274] [canon_dr] sane_read: finish 0
[15:37:33.404401] [canon_dr] sane_read: start
[15:37:33.404416] [canon_dr] read_from_buffer: start
[15:37:33.404429] [canon_dr] read_from_buffer: si:0 to:3974600 tx:65536 bu:32768 pa:32768
[15:37:33.404448] [canon_dr] read_from_buffer: finished
[15:37:33.404461] [canon_dr] check_for_cancel: start
[15:37:33.404473] [canon_dr] check_for_cancel: finish 0
[15:37:33.404485] [canon_dr] sane_read: finish 0
[15:37:33.404591] [canon_dr] sane_read: start
[15:37:33.404607] [canon_dr] read_from_buffer: start
[15:37:33.404619] [canon_dr] read_from_buffer: si:0 to:3974600 tx:98304 bu:32768 pa:32768
[15:37:33.404638] [canon_dr] read_from_buffer: finished
[15:37:33.404651] [canon_dr] check_for_cancel: start
[15:37:33.404663] [canon_dr] check_for_cancel: finish 0
[15:37:33.404676] [canon_dr] sane_read: finish 0
[15:37:33.404784] [canon_dr] sane_read: start
[15:37:33.404798] [canon_dr] read_from_buffer: start
[15:37:33.404811] [canon_dr] read_from_buffer: si:0 to:3974600 tx:131072 bu:32768 pa:32768
[15:37:33.404831] [canon_dr] read_from_buffer: finished
[15:37:33.404844] [canon_dr] check_for_cancel: start
[15:37:33.404856] [canon_dr] check_for_cancel: finish 0
[15:37:33.404868] [canon_dr] sane_read: finish 0
[15:37:33.404975] [canon_dr] sane_read: start
[15:37:33.404990] [canon_dr] read_from_buffer: start
[15:37:33.405002] [canon_dr] read_from_buffer: si:0 to:3974600 tx:163840 bu:32768 pa:32768
[15:37:33.405021] [canon_dr] read_from_buffer: finished
[15:37:33.405033] [canon_dr] check_for_cancel: start
[15:37:33.405045] [canon_dr] check_for_cancel: finish 0
[15:37:33.405058] [canon_dr] sane_read: finish 0
[15:37:33.405162] [canon_dr] sane_read: start
[15:37:33.405177] [canon_dr] read_from_buffer: start
[15:37:33.405190] [canon_dr] read_from_buffer: si:0 to:3974600 tx:196608 bu:32768 pa:32768
[15:37:33.405217] [canon_dr] read_from_buffer: finished
[15:37:33.405230] [canon_dr] check_for_cancel: start
[15:37:33.405242] [canon_dr] check_for_cancel: finish 0
[15:37:33.405255] [canon_dr] sane_read: finish 0
[15:37:33.405361] [canon_dr] sane_read: start
[15:37:33.405376] [canon_dr] read_from_buffer: start
[15:37:33.405389] [canon_dr] read_from_buffer: si:0 to:3974600 tx:229376 bu:32768 pa:32768
[15:37:33.405406] [canon_dr] read_from_buffer: finished
[15:37:33.405419] [canon_dr] check_for_cancel: start
[15:37:33.405431] [canon_dr] check_for_cancel: finish 0
[15:37:33.405444] [canon_dr] sane_read: finish 0
[15:37:33.405546] [canon_dr] sane_read: start
[15:37:33.405563] [canon_dr] read_from_buffer: start
[15:37:33.405575] [canon_dr] read_from_buffer: si:0 to:3974600 tx:262144 bu:32768 pa:32768
[15:37:33.405595] [canon_dr] read_from_buffer: finished
[15:37:33.405607] [canon_dr] check_for_cancel: start
[15:37:33.405620] [canon_dr] check_for_cancel: finish 0
[15:37:33.405632] [canon_dr] sane_read: finish 0
[15:37:33.405755] [canon_dr] sane_read: start
[15:37:33.405774] [canon_dr] read_from_buffer: start
[15:37:33.405787] [canon_dr] read_from_buffer: si:0 to:3974600 tx:294912 bu:32768 pa:32768
[15:37:33.405806] [canon_dr] read_from_buffer: finished
[15:37:33.405818] [canon_dr] check_for_cancel: start
[15:37:33.405830] [canon_dr] check_for_cancel: finish 0
[15:37:33.405842] [canon_dr] sane_read: finish 0
[15:37:33.405957] [canon_dr] sane_read: start
[15:37:33.405976] [canon_dr] read_from_buffer: start
[15:37:33.405989] [canon_dr] read_from_buffer: si:0 to:3974600 tx:327680 bu:32768 pa:32768
[15:37:33.406006] [canon_dr] read_from_buffer: finished
[15:37:33.406019] [canon_dr] check_for_cancel: start
[15:37:33.406031] [canon_dr] check_for_cancel: finish 0
[15:37:33.406044] [canon_dr] sane_read: finish 0
[15:37:33.406152] [canon_dr] sane_read: start
[15:37:33.406167] [canon_dr] read_from_buffer: start
[15:37:33.406179] [canon_dr] read_from_buffer: si:0 to:3974600 tx:360448 bu:32768 pa:32768
[15:37:33.406198] [canon_dr] read_from_buffer: finished
[15:37:33.406211] [canon_dr] check_for_cancel: start
[15:37:33.406222] [canon_dr] check_for_cancel: finish 0
[15:37:33.406235] [canon_dr] sane_read: finish 0
[15:37:33.406339] [canon_dr] sane_read: start
[15:37:33.406354] [canon_dr] read_from_buffer: start
[15:37:33.406366] [canon_dr] read_from_buffer: si:0 to:3974600 tx:393216 bu:32768 pa:32768
[15:37:33.406385] [canon_dr] read_from_buffer: finished
[15:37:33.406397] [canon_dr] check_for_cancel: start
[15:37:33.406409] [canon_dr] check_for_cancel: finish 0
[15:37:33.406421] [canon_dr] sane_read: finish 0
[15:37:33.406529] [canon_dr] sane_read: start
[15:37:33.406544] [canon_dr] read_from_buffer: start
[15:37:33.406556] [canon_dr] read_from_buffer: si:0 to:3974600 tx:425984 bu:32768 pa:32768
[15:37:33.406575] [canon_dr] read_from_buffer: finished
[15:37:33.406588] [canon_dr] check_for_cancel: start
[15:37:33.406600] [canon_dr] check_for_cancel: finish 0
[15:37:33.406612] [canon_dr] sane_read: finish 0
[15:37:33.406721] [canon_dr] sane_read: start
[15:37:33.406736] [canon_dr] read_from_buffer: start
[15:37:33.406748] [canon_dr] read_from_buffer: si:0 to:3974600 tx:458752 bu:32768 pa:32768
[15:37:33.406767] [canon_dr] read_from_buffer: finished
[15:37:33.406780] [canon_dr] check_for_cancel: start
[15:37:33.406792] [canon_dr] check_for_cancel: finish 0
[15:37:33.406804] [canon_dr] sane_read: finish 0
[15:37:33.406910] [canon_dr] sane_read: start
[15:37:33.406925] [canon_dr] read_from_buffer: start
[15:37:33.406937] [canon_dr] read_from_buffer: si:0 to:3974600 tx:491520 bu:32768 pa:32768
[15:37:33.406954] [canon_dr] read_from_buffer: finished
[15:37:33.406967] [canon_dr] check_for_cancel: start
[15:37:33.406979] [canon_dr] check_for_cancel: finish 0
[15:37:33.406991] [canon_dr] sane_read: finish 0
[15:37:33.407099] [canon_dr] sane_read: start
[15:37:33.407115] [canon_dr] read_from_buffer: start
[15:37:33.407127] [canon_dr] read_from_buffer: si:0 to:3974600 tx:524288 bu:32768 pa:32768
[15:37:33.407146] [canon_dr] read_from_buffer: finished
[15:37:33.407167] [canon_dr] check_for_cancel: start
[15:37:33.407179] [canon_dr] check_for_cancel: finish 0
[15:37:33.407191] [canon_dr] sane_read: finish 0
[15:37:33.407304] [canon_dr] sane_read: start
[15:37:33.407319] [canon_dr] read_from_buffer: start
[15:37:33.407331] [canon_dr] read_from_buffer: si:0 to:3974600 tx:557056 bu:32768 pa:32768
[15:37:33.407350] [canon_dr] read_from_buffer: finished
[15:37:33.407363] [canon_dr] check_for_cancel: start
[15:37:33.407375] [canon_dr] check_for_cancel: finish 0
[15:37:33.407387] [canon_dr] sane_read: finish 0
[15:37:33.407510] [canon_dr] sane_read: start
[15:37:33.407525] [canon_dr] read_from_buffer: start
[15:37:33.407537] [canon_dr] read_from_buffer: si:0 to:3974600 tx:589824 bu:32768 pa:32768
[15:37:33.407554] [canon_dr] read_from_buffer: finished
[15:37:33.407565] [canon_dr] check_for_cancel: start
[15:37:33.407575] [canon_dr] check_for_cancel: finish 0
[15:37:33.407586] [canon_dr] sane_read: finish 0
[15:37:33.407720] [canon_dr] sane_read: start
[15:37:33.407736] [canon_dr] read_from_buffer: start
[15:37:33.407749] [canon_dr] read_from_buffer: si:0 to:3974600 tx:622592 bu:32768 pa:32768
[15:37:33.407767] [canon_dr] read_from_buffer: finished
[15:37:33.407779] [canon_dr] check_for_cancel: start
[15:37:33.407791] [canon_dr] check_for_cancel: finish 0
[15:37:33.407804] [canon_dr] sane_read: finish 0
[15:37:33.407951] [canon_dr] sane_read: start
[15:37:33.407967] [canon_dr] read_from_buffer: start
[15:37:33.407979] [canon_dr] read_from_buffer: si:0 to:3974600 tx:655360 bu:32768 pa:32768
[15:37:33.407999] [canon_dr] read_from_buffer: finished
[15:37:33.408012] [canon_dr] check_for_cancel: start
[15:37:33.408024] [canon_dr] check_for_cancel: finish 0
[15:37:33.408036] [canon_dr] sane_read: finish 0
[15:37:33.408170] [canon_dr] sane_read: start
[15:37:33.408186] [canon_dr] read_from_buffer: start
[15:37:33.408198] [canon_dr] read_from_buffer: si:0 to:3974600 tx:688128 bu:32768 pa:32768
[15:37:33.408218] [canon_dr] read_from_buffer: finished
[15:37:33.408231] [canon_dr] check_for_cancel: start
[15:37:33.408244] [canon_dr] check_for_cancel: finish 0
[15:37:33.408256] [canon_dr] sane_read: finish 0
[15:37:33.408376] [canon_dr] sane_read: start
[15:37:33.408391] [canon_dr] read_from_buffer: start
[15:37:33.408404] [canon_dr] read_from_buffer: si:0 to:3974600 tx:720896 bu:32768 pa:32768
[15:37:33.408423] [canon_dr] read_from_buffer: finished
[15:37:33.408436] [canon_dr] check_for_cancel: start
[15:37:33.408449] [canon_dr] check_for_cancel: finish 0
[15:37:33.408461] [canon_dr] sane_read: finish 0
[15:37:33.408575] [canon_dr] sane_read: start
[15:37:33.408590] [canon_dr] read_from_buffer: start
[15:37:33.408602] [canon_dr] read_from_buffer: si:0 to:3974600 tx:753664 bu:32768 pa:32768
[15:37:33.408622] [canon_dr] read_from_buffer: finished
[15:37:33.408635] [canon_dr] check_for_cancel: start
[15:37:33.408647] [canon_dr] check_for_cancel: finish 0
[15:37:33.408660] [canon_dr] sane_read: finish 0
[15:37:33.408770] [canon_dr] sane_read: start
[15:37:33.408786] [canon_dr] read_from_buffer: start
[15:37:33.408798] [canon_dr] read_from_buffer: si:0 to:3974600 tx:786432 bu:32768 pa:32768
[15:37:33.408819] [canon_dr] read_from_buffer: finished
[15:37:33.408831] [canon_dr] check_for_cancel: start
[15:37:33.408843] [canon_dr] check_for_cancel: finish 0
[15:37:33.408856] [canon_dr] sane_read: finish 0
[15:37:33.408963] [canon_dr] sane_read: start
[15:37:33.408978] [canon_dr] read_from_buffer: start
[15:37:33.408990] [canon_dr] read_from_buffer: si:0 to:3974600 tx:819200 bu:32768 pa:32768
[15:37:33.409010] [canon_dr] read_from_buffer: finished
[15:37:33.409023] [canon_dr] check_for_cancel: start
[15:37:33.409035] [canon_dr] check_for_cancel: finish 0
[15:37:33.409048] [canon_dr] sane_read: finish 0
[15:37:33.409159] [canon_dr] sane_read: start
[15:37:33.409175] [canon_dr] read_from_buffer: start
[15:37:33.409187] [canon_dr] read_from_buffer: si:0 to:3974600 tx:851968 bu:32768 pa:32768
[15:37:33.409206] [canon_dr] read_from_buffer: finished
[15:37:33.409218] [canon_dr] check_for_cancel: start
[15:37:33.409238] [canon_dr] check_for_cancel: finish 0
[15:37:33.409251] [canon_dr] sane_read: finish 0
[15:37:33.409358] [canon_dr] sane_read: start
[15:37:33.409373] [canon_dr] read_from_buffer: start
[15:37:33.409385] [canon_dr] read_from_buffer: si:0 to:3974600 tx:884736 bu:32768 pa:32768
[15:37:33.409404] [canon_dr] read_from_buffer: finished
[15:37:33.409418] [canon_dr] check_for_cancel: start
[15:37:33.409430] [canon_dr] check_for_cancel: finish 0
[15:37:33.409442] [canon_dr] sane_read: finish 0
[15:37:33.409548] [canon_dr] sane_read: start
[15:37:33.409564] [canon_dr] read_from_buffer: start
[15:37:33.409574] [canon_dr] read_from_buffer: si:0 to:3974600 tx:917504 bu:32768 pa:32768
[15:37:33.409593] [canon_dr] read_from_buffer: finished
[15:37:33.409605] [canon_dr] check_for_cancel: start
[15:37:33.409617] [canon_dr] check_for_cancel: finish 0
[15:37:33.409630] [canon_dr] sane_read: finish 0
[15:37:33.409748] [canon_dr] sane_read: start
[15:37:33.409766] [canon_dr] read_from_buffer: start
[15:37:33.409778] [canon_dr] read_from_buffer: si:0 to:3974600 tx:950272 bu:32768 pa:32768
[15:37:33.409797] [canon_dr] read_from_buffer: finished
[15:37:33.409811] [canon_dr] check_for_cancel: start
[15:37:33.409823] [canon_dr] check_for_cancel: finish 0
[15:37:33.409835] [canon_dr] sane_read: finish 0
[15:37:33.409961] [canon_dr] sane_read: start
[15:37:33.409977] [canon_dr] read_from_buffer: start
[15:37:33.409988] [canon_dr] read_from_buffer: si:0 to:3974600 tx:983040 bu:32768 pa:32768
[15:37:33.410008] [canon_dr] read_from_buffer: finished
[15:37:33.410021] [canon_dr] check_for_cancel: start
[15:37:33.410033] [canon_dr] check_for_cancel: finish 0
[15:37:33.410045] [canon_dr] sane_read: finish 0
[15:37:33.410159] [canon_dr] sane_read: start
[15:37:33.410175] [canon_dr] read_from_buffer: start
[15:37:33.410187] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1015808 bu:32768 pa:32768
[15:37:33.410208] [canon_dr] read_from_buffer: finished
[15:37:33.410220] [canon_dr] check_for_cancel: start
[15:37:33.410232] [canon_dr] check_for_cancel: finish 0
[15:37:33.410245] [canon_dr] sane_read: finish 0
[15:37:33.410359] [canon_dr] sane_read: start
[15:37:33.410375] [canon_dr] read_from_buffer: start
[15:37:33.410387] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1048576 bu:32768 pa:32768
[15:37:33.410406] [canon_dr] read_from_buffer: finished
[15:37:33.410419] [canon_dr] check_for_cancel: start
[15:37:33.410431] [canon_dr] check_for_cancel: finish 0
[15:37:33.410442] [canon_dr] sane_read: finish 0
[15:37:33.410562] [canon_dr] sane_read: start
[15:37:33.410578] [canon_dr] read_from_buffer: start
[15:37:33.410590] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1081344 bu:32768 pa:32768
[15:37:33.410609] [canon_dr] read_from_buffer: finished
[15:37:33.410622] [canon_dr] check_for_cancel: start
[15:37:33.410634] [canon_dr] check_for_cancel: finish 0
[15:37:33.410646] [canon_dr] sane_read: finish 0
[15:37:33.410757] [canon_dr] sane_read: start
[15:37:33.410773] [canon_dr] read_from_buffer: start
[15:37:33.410785] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1114112 bu:32768 pa:32768
[15:37:33.410805] [canon_dr] read_from_buffer: finished
[15:37:33.410818] [canon_dr] check_for_cancel: start
[15:37:33.410830] [canon_dr] check_for_cancel: finish 0
[15:37:33.410842] [canon_dr] sane_read: finish 0
[15:37:33.410963] [canon_dr] sane_read: start
[15:37:33.410978] [canon_dr] read_from_buffer: start
[15:37:33.410991] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1146880 bu:32768 pa:32768
[15:37:33.411011] [canon_dr] read_from_buffer: finished
[15:37:33.411024] [canon_dr] check_for_cancel: start
[15:37:33.411036] [canon_dr] check_for_cancel: finish 0
[15:37:33.411048] [canon_dr] sane_read: finish 0
[15:37:33.411160] [canon_dr] sane_read: start
[15:37:33.411176] [canon_dr] read_from_buffer: start
[15:37:33.411188] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1179648 bu:32768 pa:32768
[15:37:33.411208] [canon_dr] read_from_buffer: finished
[15:37:33.411220] [canon_dr] check_for_cancel: start
[15:37:33.411232] [canon_dr] check_for_cancel: finish 0
[15:37:33.411251] [canon_dr] sane_read: finish 0
[15:37:33.411366] [canon_dr] sane_read: start
[15:37:33.411382] [canon_dr] read_from_buffer: start
[15:37:33.411394] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1212416 bu:32768 pa:32768
[15:37:33.411412] [canon_dr] read_from_buffer: finished
[15:37:33.411425] [canon_dr] check_for_cancel: start
[15:37:33.411436] [canon_dr] check_for_cancel: finish 0
[15:37:33.411449] [canon_dr] sane_read: finish 0
[15:37:33.411568] [canon_dr] sane_read: start
[15:37:33.411584] [canon_dr] read_from_buffer: start
[15:37:33.411597] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1245184 bu:32768 pa:32768
[15:37:33.411616] [canon_dr] read_from_buffer: finished
[15:37:33.411629] [canon_dr] check_for_cancel: start
[15:37:33.411641] [canon_dr] check_for_cancel: finish 0
[15:37:33.411653] [canon_dr] sane_read: finish 0
[15:37:33.411765] [canon_dr] sane_read: start
[15:37:33.411780] [canon_dr] read_from_buffer: start
[15:37:33.411793] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1277952 bu:32768 pa:32768
[15:37:33.411812] [canon_dr] read_from_buffer: finished
[15:37:33.411825] [canon_dr] check_for_cancel: start
[15:37:33.411837] [canon_dr] check_for_cancel: finish 0
[15:37:33.411849] [canon_dr] sane_read: finish 0
[15:37:33.411965] [canon_dr] sane_read: start
[15:37:33.411981] [canon_dr] read_from_buffer: start
[15:37:33.411993] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1310720 bu:32768 pa:32768
[15:37:33.412012] [canon_dr] read_from_buffer: finished
[15:37:33.412025] [canon_dr] check_for_cancel: start
[15:37:33.412037] [canon_dr] check_for_cancel: finish 0
[15:37:33.412050] [canon_dr] sane_read: finish 0
[15:37:33.412180] [canon_dr] sane_read: start
[15:37:33.412196] [canon_dr] read_from_buffer: start
[15:37:33.412208] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1343488 bu:32768 pa:32768
[15:37:33.412227] [canon_dr] read_from_buffer: finished
[15:37:33.412240] [canon_dr] check_for_cancel: start
[15:37:33.412252] [canon_dr] check_for_cancel: finish 0
[15:37:33.412265] [canon_dr] sane_read: finish 0
[15:37:33.412384] [canon_dr] sane_read: start
[15:37:33.412398] [canon_dr] read_from_buffer: start
[15:37:33.412410] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1376256 bu:32768 pa:32768
[15:37:33.412430] [canon_dr] read_from_buffer: finished
[15:37:33.412443] [canon_dr] check_for_cancel: start
[15:37:33.412455] [canon_dr] check_for_cancel: finish 0
[15:37:33.412467] [canon_dr] sane_read: finish 0
[15:37:33.412584] [canon_dr] sane_read: start
[15:37:33.412599] [canon_dr] read_from_buffer: start
[15:37:33.412611] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1409024 bu:32768 pa:32768
[15:37:33.412631] [canon_dr] read_from_buffer: finished
[15:37:33.412643] [canon_dr] check_for_cancel: start
[15:37:33.412655] [canon_dr] check_for_cancel: finish 0
[15:37:33.412667] [canon_dr] sane_read: finish 0
[15:37:33.412790] [canon_dr] sane_read: start
[15:37:33.412806] [canon_dr] read_from_buffer: start
[15:37:33.412818] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1441792 bu:32768 pa:32768
[15:37:33.412837] [canon_dr] read_from_buffer: finished
[15:37:33.412856] [canon_dr] check_for_cancel: start
[15:37:33.412868] [canon_dr] check_for_cancel: finish 0
[15:37:33.412881] [canon_dr] sane_read: finish 0
[15:37:33.412998] [canon_dr] sane_read: start
[15:37:33.413014] [canon_dr] read_from_buffer: start
[15:37:33.413026] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1474560 bu:32768 pa:32768
[15:37:33.413045] [canon_dr] read_from_buffer: finished
[15:37:33.413058] [canon_dr] check_for_cancel: start
[15:37:33.413070] [canon_dr] check_for_cancel: finish 0
[15:37:33.413083] [canon_dr] sane_read: finish 0
[15:37:33.413202] [canon_dr] sane_read: start
[15:37:33.413218] [canon_dr] read_from_buffer: start
[15:37:33.413230] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1507328 bu:32768 pa:32768
[15:37:33.413249] [canon_dr] read_from_buffer: finished
[15:37:33.413262] [canon_dr] check_for_cancel: start
[15:37:33.413274] [canon_dr] check_for_cancel: finish 0
[15:37:33.413294] [canon_dr] sane_read: finish 0
[15:37:33.413400] [canon_dr] sane_read: start
[15:37:33.413415] [canon_dr] read_from_buffer: start
[15:37:33.413427] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1540096 bu:32768 pa:32768
[15:37:33.413446] [canon_dr] read_from_buffer: finished
[15:37:33.413459] [canon_dr] check_for_cancel: start
[15:37:33.413471] [canon_dr] check_for_cancel: finish 0
[15:37:33.413483] [canon_dr] sane_read: finish 0
[15:37:33.413588] [canon_dr] sane_read: start
[15:37:33.413604] [canon_dr] read_from_buffer: start
[15:37:33.413617] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1572864 bu:32768 pa:32768
[15:37:33.413636] [canon_dr] read_from_buffer: finished
[15:37:33.413649] [canon_dr] check_for_cancel: start
[15:37:33.413661] [canon_dr] check_for_cancel: finish 0
[15:37:33.413673] [canon_dr] sane_read: finish 0
[15:37:33.413796] [canon_dr] sane_read: start
[15:37:33.413814] [canon_dr] read_from_buffer: start
[15:37:33.413827] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1605632 bu:32768 pa:32768
[15:37:33.413846] [canon_dr] read_from_buffer: finished
[15:37:33.413860] [canon_dr] check_for_cancel: start
[15:37:33.413872] [canon_dr] check_for_cancel: finish 0
[15:37:33.413884] [canon_dr] sane_read: finish 0
[15:37:33.413996] [canon_dr] sane_read: start
[15:37:33.414011] [canon_dr] read_from_buffer: start
[15:37:33.414023] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1638400 bu:32768 pa:32768
[15:37:33.414043] [canon_dr] read_from_buffer: finished
[15:37:33.414056] [canon_dr] check_for_cancel: start
[15:37:33.414068] [canon_dr] check_for_cancel: finish 0
[15:37:33.414080] [canon_dr] sane_read: finish 0
[15:37:33.414189] [canon_dr] sane_read: start
[15:37:33.414204] [canon_dr] read_from_buffer: start
[15:37:33.414216] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1671168 bu:32768 pa:32768
[15:37:33.414236] [canon_dr] read_from_buffer: finished
[15:37:33.414248] [canon_dr] check_for_cancel: start
[15:37:33.414261] [canon_dr] check_for_cancel: finish 0
[15:37:33.414273] [canon_dr] sane_read: finish 0
[15:37:33.414378] [canon_dr] sane_read: start
[15:37:33.414393] [canon_dr] read_from_buffer: start
[15:37:33.414405] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1703936 bu:32768 pa:32768
[15:37:33.414423] [canon_dr] read_from_buffer: finished
[15:37:33.414436] [canon_dr] check_for_cancel: start
[15:37:33.414448] [canon_dr] check_for_cancel: finish 0
[15:37:33.414460] [canon_dr] sane_read: finish 0
[15:37:33.414569] [canon_dr] sane_read: start
[15:37:33.414585] [canon_dr] read_from_buffer: start
[15:37:33.414597] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1736704 bu:32768 pa:32768
[15:37:33.414616] [canon_dr] read_from_buffer: finished
[15:37:33.414629] [canon_dr] check_for_cancel: start
[15:37:33.414641] [canon_dr] check_for_cancel: finish 0
[15:37:33.414654] [canon_dr] sane_read: finish 0
[15:37:33.414759] [canon_dr] sane_read: start
[15:37:33.414775] [canon_dr] read_from_buffer: start
[15:37:33.414787] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1769472 bu:32768 pa:32768
[15:37:33.414806] [canon_dr] read_from_buffer: finished
[15:37:33.414819] [canon_dr] check_for_cancel: start
[15:37:33.414832] [canon_dr] check_for_cancel: finish 0
[15:37:33.414844] [canon_dr] sane_read: finish 0
[15:37:33.414954] [canon_dr] sane_read: start
[15:37:33.414970] [canon_dr] read_from_buffer: start
[15:37:33.414982] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1802240 bu:32768 pa:32768
[15:37:33.415002] [canon_dr] read_from_buffer: finished
[15:37:33.415015] [canon_dr] check_for_cancel: start
[15:37:33.415027] [canon_dr] check_for_cancel: finish 0
[15:37:33.415039] [canon_dr] sane_read: finish 0
[15:37:33.415145] [canon_dr] sane_read: start
[15:37:33.415160] [canon_dr] read_from_buffer: start
[15:37:33.415173] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1835008 bu:32768 pa:32768
[15:37:33.415192] [canon_dr] read_from_buffer: finished
[15:37:33.415204] [canon_dr] check_for_cancel: start
[15:37:33.415216] [canon_dr] check_for_cancel: finish 0
[15:37:33.415229] [canon_dr] sane_read: finish 0
[15:37:33.415356] [canon_dr] sane_read: start
[15:37:33.415372] [canon_dr] read_from_buffer: start
[15:37:33.415384] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1867776 bu:32768 pa:32768
[15:37:33.415404] [canon_dr] read_from_buffer: finished
[15:37:33.415417] [canon_dr] check_for_cancel: start
[15:37:33.415429] [canon_dr] check_for_cancel: finish 0
[15:37:33.415442] [canon_dr] sane_read: finish 0
[15:37:33.415548] [canon_dr] sane_read: start
[15:37:33.415561] [canon_dr] read_from_buffer: start
[15:37:33.415572] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1900544 bu:32768 pa:32768
[15:37:33.415588] [canon_dr] read_from_buffer: finished
[15:37:33.415599] [canon_dr] check_for_cancel: start
[15:37:33.415609] [canon_dr] check_for_cancel: finish 0
[15:37:33.415620] [canon_dr] sane_read: finish 0
[15:37:33.415729] [canon_dr] sane_read: start
[15:37:33.415744] [canon_dr] read_from_buffer: start
[15:37:33.415756] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1933312 bu:32768 pa:32768
[15:37:33.415775] [canon_dr] read_from_buffer: finished
[15:37:33.415787] [canon_dr] check_for_cancel: start
[15:37:33.415800] [canon_dr] check_for_cancel: finish 0
[15:37:33.415812] [canon_dr] sane_read: finish 0
[15:37:33.415918] [canon_dr] sane_read: start
[15:37:33.415933] [canon_dr] read_from_buffer: start
[15:37:33.415945] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1966080 bu:32768 pa:32768
[15:37:33.415965] [canon_dr] read_from_buffer: finished
[15:37:33.415978] [canon_dr] check_for_cancel: start
[15:37:33.415990] [canon_dr] check_for_cancel: finish 0
[15:37:33.416003] [canon_dr] sane_read: finish 0
[15:37:33.416113] [canon_dr] sane_read: start
[15:37:33.416128] [canon_dr] read_from_buffer: start
[15:37:33.416141] [canon_dr] read_from_buffer: si:0 to:3974600 tx:1998848 bu:32768 pa:32768
[15:37:33.416160] [canon_dr] read_from_buffer: finished
[15:37:33.416173] [canon_dr] check_for_cancel: start
[15:37:33.416185] [canon_dr] check_for_cancel: finish 0
[15:37:33.416197] [canon_dr] sane_read: finish 0
[15:37:33.416304] [canon_dr] sane_read: start
[15:37:33.416320] [canon_dr] read_from_buffer: start
[15:37:33.416332] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2031616 bu:32768 pa:32768
[15:37:33.416351] [canon_dr] read_from_buffer: finished
[15:37:33.416364] [canon_dr] check_for_cancel: start
[15:37:33.416376] [canon_dr] check_for_cancel: finish 0
[15:37:33.416388] [canon_dr] sane_read: finish 0
[15:37:33.416498] [canon_dr] sane_read: start
[15:37:33.416513] [canon_dr] read_from_buffer: start
[15:37:33.416525] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2064384 bu:32768 pa:32768
[15:37:33.416543] [canon_dr] read_from_buffer: finished
[15:37:33.416556] [canon_dr] check_for_cancel: start
[15:37:33.416568] [canon_dr] check_for_cancel: finish 0
[15:37:33.416581] [canon_dr] sane_read: finish 0
[15:37:33.416690] [canon_dr] sane_read: start
[15:37:33.416706] [canon_dr] read_from_buffer: start
[15:37:33.416718] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2097152 bu:32768 pa:32768
[15:37:33.416736] [canon_dr] read_from_buffer: finished
[15:37:33.416749] [canon_dr] check_for_cancel: start
[15:37:33.416761] [canon_dr] check_for_cancel: finish 0
[15:37:33.416773] [canon_dr] sane_read: finish 0
[15:37:33.416889] [canon_dr] sane_read: start
[15:37:33.416905] [canon_dr] read_from_buffer: start
[15:37:33.416918] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2129920 bu:32768 pa:32768
[15:37:33.416938] [canon_dr] read_from_buffer: finished
[15:37:33.416951] [canon_dr] check_for_cancel: start
[15:37:33.416963] [canon_dr] check_for_cancel: finish 0
[15:37:33.416975] [canon_dr] sane_read: finish 0
[15:37:33.417086] [canon_dr] sane_read: start
[15:37:33.417102] [canon_dr] read_from_buffer: start
[15:37:33.417114] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2162688 bu:32768 pa:32768
[15:37:33.417134] [canon_dr] read_from_buffer: finished
[15:37:33.417147] [canon_dr] check_for_cancel: start
[15:37:33.417159] [canon_dr] check_for_cancel: finish 0
[15:37:33.417171] [canon_dr] sane_read: finish 0
[15:37:33.417280] [canon_dr] sane_read: start
[15:37:33.417302] [canon_dr] read_from_buffer: start
[15:37:33.417315] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2195456 bu:32768 pa:32768
[15:37:33.417334] [canon_dr] read_from_buffer: finished
[15:37:33.417347] [canon_dr] check_for_cancel: start
[15:37:33.417359] [canon_dr] check_for_cancel: finish 0
[15:37:33.417371] [canon_dr] sane_read: finish 0
[15:37:33.417480] [canon_dr] sane_read: start
[15:37:33.417495] [canon_dr] read_from_buffer: start
[15:37:33.417508] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2228224 bu:32768 pa:32768
[15:37:33.417526] [canon_dr] read_from_buffer: finished
[15:37:33.417539] [canon_dr] check_for_cancel: start
[15:37:33.417550] [canon_dr] check_for_cancel: finish 0
[15:37:33.417560] [canon_dr] sane_read: finish 0
[15:37:33.417661] [canon_dr] sane_read: start
[15:37:33.417673] [canon_dr] read_from_buffer: start
[15:37:33.417683] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2260992 bu:32768 pa:32768
[15:37:33.417699] [canon_dr] read_from_buffer: finished
[15:37:33.417709] [canon_dr] check_for_cancel: start
[15:37:33.417720] [canon_dr] check_for_cancel: finish 0
[15:37:33.417740] [canon_dr] sane_read: finish 0
[15:37:33.417850] [canon_dr] sane_read: start
[15:37:33.417866] [canon_dr] read_from_buffer: start
[15:37:33.417878] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2293760 bu:32768 pa:32768
[15:37:33.417897] [canon_dr] read_from_buffer: finished
[15:37:33.417910] [canon_dr] check_for_cancel: start
[15:37:33.417922] [canon_dr] check_for_cancel: finish 0
[15:37:33.417934] [canon_dr] sane_read: finish 0
[15:37:33.418041] [canon_dr] sane_read: start
[15:37:33.418056] [canon_dr] read_from_buffer: start
[15:37:33.418068] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2326528 bu:32768 pa:32768
[15:37:33.418087] [canon_dr] read_from_buffer: finished
[15:37:33.418100] [canon_dr] check_for_cancel: start
[15:37:33.418112] [canon_dr] check_for_cancel: finish 0
[15:37:33.418124] [canon_dr] sane_read: finish 0
[15:37:33.418243] [canon_dr] sane_read: start
[15:37:33.418258] [canon_dr] read_from_buffer: start
[15:37:33.418270] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2359296 bu:32768 pa:32768
[15:37:33.418289] [canon_dr] read_from_buffer: finished
[15:37:33.418302] [canon_dr] check_for_cancel: start
[15:37:33.418313] [canon_dr] check_for_cancel: finish 0
[15:37:33.418326] [canon_dr] sane_read: finish 0
[15:37:33.418434] [canon_dr] sane_read: start
[15:37:33.418448] [canon_dr] read_from_buffer: start
[15:37:33.418460] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2392064 bu:32768 pa:32768
[15:37:33.418478] [canon_dr] read_from_buffer: finished
[15:37:33.418490] [canon_dr] check_for_cancel: start
[15:37:33.418502] [canon_dr] check_for_cancel: finish 0
[15:37:33.418514] [canon_dr] sane_read: finish 0
[15:37:33.418624] [canon_dr] sane_read: start
[15:37:33.418638] [canon_dr] read_from_buffer: start
[15:37:33.418651] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2424832 bu:32768 pa:32768
[15:37:33.418669] [canon_dr] read_from_buffer: finished
[15:37:33.418682] [canon_dr] check_for_cancel: start
[15:37:33.418695] [canon_dr] check_for_cancel: finish 0
[15:37:33.418707] [canon_dr] sane_read: finish 0
[15:37:33.418814] [canon_dr] sane_read: start
[15:37:33.418829] [canon_dr] read_from_buffer: start
[15:37:33.418841] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2457600 bu:32768 pa:32768
[15:37:33.418861] [canon_dr] read_from_buffer: finished
[15:37:33.418874] [canon_dr] check_for_cancel: start
[15:37:33.418885] [canon_dr] check_for_cancel: finish 0
[15:37:33.418898] [canon_dr] sane_read: finish 0
[15:37:33.419008] [canon_dr] sane_read: start
[15:37:33.419022] [canon_dr] read_from_buffer: start
[15:37:33.419034] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2490368 bu:32768 pa:32768
[15:37:33.419053] [canon_dr] read_from_buffer: finished
[15:37:33.419066] [canon_dr] check_for_cancel: start
[15:37:33.419078] [canon_dr] check_for_cancel: finish 0
[15:37:33.419090] [canon_dr] sane_read: finish 0
[15:37:33.419201] [canon_dr] sane_read: start
[15:37:33.419216] [canon_dr] read_from_buffer: start
[15:37:33.419234] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2523136 bu:32768 pa:32768
[15:37:33.419253] [canon_dr] read_from_buffer: finished
[15:37:33.419266] [canon_dr] check_for_cancel: start
[15:37:33.419278] [canon_dr] check_for_cancel: finish 0
[15:37:33.419291] [canon_dr] sane_read: finish 0
[15:37:33.419397] [canon_dr] sane_read: start
[15:37:33.419410] [canon_dr] read_from_buffer: start
[15:37:33.419423] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2555904 bu:32768 pa:32768
[15:37:33.419441] [canon_dr] read_from_buffer: finished
[15:37:33.419452] [canon_dr] check_for_cancel: start
[15:37:33.419462] [canon_dr] check_for_cancel: finish 0
[15:37:33.419472] [canon_dr] sane_read: finish 0
[15:37:33.419576] [canon_dr] sane_read: start
[15:37:33.419588] [canon_dr] read_from_buffer: start
[15:37:33.419598] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2588672 bu:32768 pa:32768
[15:37:33.419614] [canon_dr] read_from_buffer: finished
[15:37:33.419624] [canon_dr] check_for_cancel: start
[15:37:33.419636] [canon_dr] check_for_cancel: finish 0
[15:37:33.419647] [canon_dr] sane_read: finish 0
[15:37:33.419757] [canon_dr] sane_read: start
[15:37:33.419770] [canon_dr] read_from_buffer: start
[15:37:33.419780] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2621440 bu:32768 pa:32768
[15:37:33.419799] [canon_dr] read_from_buffer: finished
[15:37:33.419813] [canon_dr] check_for_cancel: start
[15:37:33.419824] [canon_dr] check_for_cancel: finish 0
[15:37:33.419837] [canon_dr] sane_read: finish 0
[15:37:33.419946] [canon_dr] sane_read: start
[15:37:33.419961] [canon_dr] read_from_buffer: start
[15:37:33.419974] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2654208 bu:32768 pa:32768
[15:37:33.419992] [canon_dr] read_from_buffer: finished
[15:37:33.420004] [canon_dr] check_for_cancel: start
[15:37:33.420016] [canon_dr] check_for_cancel: finish 0
[15:37:33.420028] [canon_dr] sane_read: finish 0
[15:37:33.420135] [canon_dr] sane_read: start
[15:37:33.420150] [canon_dr] read_from_buffer: start
[15:37:33.420163] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2686976 bu:32768 pa:32768
[15:37:33.420180] [canon_dr] read_from_buffer: finished
[15:37:33.420193] [canon_dr] check_for_cancel: start
[15:37:33.420205] [canon_dr] check_for_cancel: finish 0
[15:37:33.420217] [canon_dr] sane_read: finish 0
[15:37:33.420325] [canon_dr] sane_read: start
[15:37:33.420340] [canon_dr] read_from_buffer: start
[15:37:33.420352] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2719744 bu:32768 pa:32768
[15:37:33.420371] [canon_dr] read_from_buffer: finished
[15:37:33.420384] [canon_dr] check_for_cancel: start
[15:37:33.420395] [canon_dr] check_for_cancel: finish 0
[15:37:33.420407] [canon_dr] sane_read: finish 0
[15:37:33.420512] [canon_dr] sane_read: start
[15:37:33.420526] [canon_dr] read_from_buffer: start
[15:37:33.420538] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2752512 bu:32768 pa:32768
[15:37:33.420558] [canon_dr] read_from_buffer: finished
[15:37:33.420571] [canon_dr] check_for_cancel: start
[15:37:33.420583] [canon_dr] check_for_cancel: finish 0
[15:37:33.420595] [canon_dr] sane_read: finish 0
[15:37:33.420704] [canon_dr] sane_read: start
[15:37:33.420719] [canon_dr] read_from_buffer: start
[15:37:33.420731] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2785280 bu:32768 pa:32768
[15:37:33.420750] [canon_dr] read_from_buffer: finished
[15:37:33.420763] [canon_dr] check_for_cancel: start
[15:37:33.420775] [canon_dr] check_for_cancel: finish 0
[15:37:33.420787] [canon_dr] sane_read: finish 0
[15:37:33.420892] [canon_dr] sane_read: start
[15:37:33.420907] [canon_dr] read_from_buffer: start
[15:37:33.420920] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2818048 bu:32768 pa:32768
[15:37:33.420938] [canon_dr] read_from_buffer: finished
[15:37:33.420951] [canon_dr] check_for_cancel: start
[15:37:33.420963] [canon_dr] check_for_cancel: finish 0
[15:37:33.420975] [canon_dr] sane_read: finish 0
[15:37:33.421082] [canon_dr] sane_read: start
[15:37:33.421097] [canon_dr] read_from_buffer: start
[15:37:33.421109] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2850816 bu:32768 pa:32768
[15:37:33.421135] [canon_dr] read_from_buffer: finished
[15:37:33.421148] [canon_dr] check_for_cancel: start
[15:37:33.421160] [canon_dr] check_for_cancel: finish 0
[15:37:33.421172] [canon_dr] sane_read: finish 0
[15:37:33.421290] [canon_dr] sane_read: start
[15:37:33.421306] [canon_dr] read_from_buffer: start
[15:37:33.421318] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2883584 bu:32768 pa:32768
[15:37:33.421336] [canon_dr] read_from_buffer: finished
[15:37:33.421348] [canon_dr] check_for_cancel: start
[15:37:33.421360] [canon_dr] check_for_cancel: finish 0
[15:37:33.421372] [canon_dr] sane_read: finish 0
[15:37:33.421477] [canon_dr] sane_read: start
[15:37:33.421492] [canon_dr] read_from_buffer: start
[15:37:33.421504] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2916352 bu:32768 pa:32768
[15:37:33.421523] [canon_dr] read_from_buffer: finished
[15:37:33.421536] [canon_dr] check_for_cancel: start
[15:37:33.421548] [canon_dr] check_for_cancel: finish 0
[15:37:33.421560] [canon_dr] sane_read: finish 0
[15:37:33.421666] [canon_dr] sane_read: start
[15:37:33.421682] [canon_dr] read_from_buffer: start
[15:37:33.421693] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2949120 bu:32768 pa:32768
[15:37:33.421712] [canon_dr] read_from_buffer: finished
[15:37:33.421734] [canon_dr] check_for_cancel: start
[15:37:33.421747] [canon_dr] check_for_cancel: finish 0
[15:37:33.421759] [canon_dr] sane_read: finish 0
[15:37:33.421867] [canon_dr] sane_read: start
[15:37:33.421884] [canon_dr] read_from_buffer: start
[15:37:33.421894] [canon_dr] read_from_buffer: si:0 to:3974600 tx:2981888 bu:32768 pa:32768
[15:37:33.421910] [canon_dr] read_from_buffer: finished
[15:37:33.421920] [canon_dr] check_for_cancel: start
[15:37:33.421930] [canon_dr] check_for_cancel: finish 0
[15:37:33.421940] [canon_dr] sane_read: finish 0
[15:37:33.422043] [canon_dr] sane_read: start
[15:37:33.422058] [canon_dr] read_from_buffer: start
[15:37:33.422070] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3014656 bu:32768 pa:32768
[15:37:33.422089] [canon_dr] read_from_buffer: finished
[15:37:33.422102] [canon_dr] check_for_cancel: start
[15:37:33.422114] [canon_dr] check_for_cancel: finish 0
[15:37:33.422126] [canon_dr] sane_read: finish 0
[15:37:33.422231] [canon_dr] sane_read: start
[15:37:33.422246] [canon_dr] read_from_buffer: start
[15:37:33.422258] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3047424 bu:32768 pa:32768
[15:37:33.422276] [canon_dr] read_from_buffer: finished
[15:37:33.422289] [canon_dr] check_for_cancel: start
[15:37:33.422301] [canon_dr] check_for_cancel: finish 0
[15:37:33.422313] [canon_dr] sane_read: finish 0
[15:37:33.422421] [canon_dr] sane_read: start
[15:37:33.422436] [canon_dr] read_from_buffer: start
[15:37:33.422448] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3080192 bu:32768 pa:32768
[15:37:33.422466] [canon_dr] read_from_buffer: finished
[15:37:33.422479] [canon_dr] check_for_cancel: start
[15:37:33.422491] [canon_dr] check_for_cancel: finish 0
[15:37:33.422503] [canon_dr] sane_read: finish 0
[15:37:33.422607] [canon_dr] sane_read: start
[15:37:33.422622] [canon_dr] read_from_buffer: start
[15:37:33.422634] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3112960 bu:32768 pa:32768
[15:37:33.422654] [canon_dr] read_from_buffer: finished
[15:37:33.422666] [canon_dr] check_for_cancel: start
[15:37:33.422678] [canon_dr] check_for_cancel: finish 0
[15:37:33.422690] [canon_dr] sane_read: finish 0
[15:37:33.422809] [canon_dr] sane_read: start
[15:37:33.422824] [canon_dr] read_from_buffer: start
[15:37:33.422836] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3145728 bu:32768 pa:32768
[15:37:33.422855] [canon_dr] read_from_buffer: finished
[15:37:33.422867] [canon_dr] check_for_cancel: start
[15:37:33.422879] [canon_dr] check_for_cancel: finish 0
[15:37:33.422891] [canon_dr] sane_read: finish 0
[15:37:33.422996] [canon_dr] sane_read: start
[15:37:33.423011] [canon_dr] read_from_buffer: start
[15:37:33.423023] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3178496 bu:32768 pa:32768
[15:37:33.423049] [canon_dr] read_from_buffer: finished
[15:37:33.423062] [canon_dr] check_for_cancel: start
[15:37:33.423074] [canon_dr] check_for_cancel: finish 0
[15:37:33.423086] [canon_dr] sane_read: finish 0
[15:37:33.423191] [canon_dr] sane_read: start
[15:37:33.423206] [canon_dr] read_from_buffer: start
[15:37:33.423218] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3211264 bu:32768 pa:32768
[15:37:33.423237] [canon_dr] read_from_buffer: finished
[15:37:33.423250] [canon_dr] check_for_cancel: start
[15:37:33.423262] [canon_dr] check_for_cancel: finish 0
[15:37:33.423274] [canon_dr] sane_read: finish 0
[15:37:33.423381] [canon_dr] sane_read: start
[15:37:33.423396] [canon_dr] read_from_buffer: start
[15:37:33.423408] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3244032 bu:32768 pa:32768
[15:37:33.423427] [canon_dr] read_from_buffer: finished
[15:37:33.423439] [canon_dr] check_for_cancel: start
[15:37:33.423451] [canon_dr] check_for_cancel: finish 0
[15:37:33.423464] [canon_dr] sane_read: finish 0
[15:37:33.423573] [canon_dr] sane_read: start
[15:37:33.423588] [canon_dr] read_from_buffer: start
[15:37:33.423600] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3276800 bu:32768 pa:32768
[15:37:33.423620] [canon_dr] read_from_buffer: finished
[15:37:33.423632] [canon_dr] check_for_cancel: start
[15:37:33.423644] [canon_dr] check_for_cancel: finish 0
[15:37:33.423656] [canon_dr] sane_read: finish 0
[15:37:33.423767] [canon_dr] sane_read: start
[15:37:33.423783] [canon_dr] read_from_buffer: start
[15:37:33.423794] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3309568 bu:32768 pa:32768
[15:37:33.423814] [canon_dr] read_from_buffer: finished
[15:37:33.423828] [canon_dr] check_for_cancel: start
[15:37:33.423840] [canon_dr] check_for_cancel: finish 0
[15:37:33.423855] [canon_dr] sane_read: finish 0
[15:37:33.423959] [canon_dr] sane_read: start
[15:37:33.423978] [canon_dr] read_from_buffer: start
[15:37:33.423990] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3342336 bu:32768 pa:32768
[15:37:33.424008] [canon_dr] read_from_buffer: finished
[15:37:33.424018] [canon_dr] check_for_cancel: start
[15:37:33.424029] [canon_dr] check_for_cancel: finish 0
[15:37:33.424041] [canon_dr] sane_read: finish 0
[15:37:33.424163] [canon_dr] sane_read: start
[15:37:33.424179] [canon_dr] read_from_buffer: start
[15:37:33.424191] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3375104 bu:32768 pa:32768
[15:37:33.424209] [canon_dr] read_from_buffer: finished
[15:37:33.424222] [canon_dr] check_for_cancel: start
[15:37:33.424234] [canon_dr] check_for_cancel: finish 0
[15:37:33.424247] [canon_dr] sane_read: finish 0
[15:37:33.424352] [canon_dr] sane_read: start
[15:37:33.424367] [canon_dr] read_from_buffer: start
[15:37:33.424379] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3407872 bu:32768 pa:32768
[15:37:33.424398] [canon_dr] read_from_buffer: finished
[15:37:33.424410] [canon_dr] check_for_cancel: start
[15:37:33.424422] [canon_dr] check_for_cancel: finish 0
[15:37:33.424434] [canon_dr] sane_read: finish 0
[15:37:33.424546] [canon_dr] sane_read: start
[15:37:33.424561] [canon_dr] read_from_buffer: start
[15:37:33.424573] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3440640 bu:32768 pa:32768
[15:37:33.424592] [canon_dr] read_from_buffer: finished
[15:37:33.424605] [canon_dr] check_for_cancel: start
[15:37:33.424616] [canon_dr] check_for_cancel: finish 0
[15:37:33.424629] [canon_dr] sane_read: finish 0
[15:37:33.424737] [canon_dr] sane_read: start
[15:37:33.424752] [canon_dr] read_from_buffer: start
[15:37:33.424764] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3473408 bu:32768 pa:32768
[15:37:33.424782] [canon_dr] read_from_buffer: finished
[15:37:33.424795] [canon_dr] check_for_cancel: start
[15:37:33.424807] [canon_dr] check_for_cancel: finish 0
[15:37:33.424819] [canon_dr] sane_read: finish 0
[15:37:33.424930] [canon_dr] sane_read: start
[15:37:33.424945] [canon_dr] read_from_buffer: start
[15:37:33.424957] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3506176 bu:32768 pa:32768
[15:37:33.424975] [canon_dr] read_from_buffer: finished
[15:37:33.424997] [canon_dr] check_for_cancel: start
[15:37:33.425009] [canon_dr] check_for_cancel: finish 0
[15:37:33.425022] [canon_dr] sane_read: finish 0
[15:37:33.425128] [canon_dr] sane_read: start
[15:37:33.425142] [canon_dr] read_from_buffer: start
[15:37:33.425155] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3538944 bu:32768 pa:32768
[15:37:33.425173] [canon_dr] read_from_buffer: finished
[15:37:33.425186] [canon_dr] check_for_cancel: start
[15:37:33.425197] [canon_dr] check_for_cancel: finish 0
[15:37:33.425210] [canon_dr] sane_read: finish 0
[15:37:33.425320] [canon_dr] sane_read: start
[15:37:33.425335] [canon_dr] read_from_buffer: start
[15:37:33.425347] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3571712 bu:32768 pa:32768
[15:37:33.425367] [canon_dr] read_from_buffer: finished
[15:37:33.425379] [canon_dr] check_for_cancel: start
[15:37:33.425391] [canon_dr] check_for_cancel: finish 0
[15:37:33.425403] [canon_dr] sane_read: finish 0
[15:37:33.425513] [canon_dr] sane_read: start
[15:37:33.425529] [canon_dr] read_from_buffer: start
[15:37:33.425540] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3604480 bu:32768 pa:32768
[15:37:33.425559] [canon_dr] read_from_buffer: finished
[15:37:33.425572] [canon_dr] check_for_cancel: start
[15:37:33.425584] [canon_dr] check_for_cancel: finish 0
[15:37:33.425596] [canon_dr] sane_read: finish 0
[15:37:33.425718] [canon_dr] sane_read: start
[15:37:33.429758] [canon_dr] read_from_buffer: start
[15:37:33.429775] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3637248 bu:32768 pa:32768
[15:37:33.429795] [canon_dr] read_from_buffer: finished
[15:37:33.429809] [canon_dr] check_for_cancel: start
[15:37:33.429820] [canon_dr] check_for_cancel: finish 0
[15:37:33.429833] [canon_dr] sane_read: finish 0
[15:37:33.429947] [canon_dr] sane_read: start
[15:37:33.429963] [canon_dr] read_from_buffer: start
[15:37:33.429975] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3670016 bu:32768 pa:32768
[15:37:33.429993] [canon_dr] read_from_buffer: finished
[15:37:33.430006] [canon_dr] check_for_cancel: start
[15:37:33.430018] [canon_dr] check_for_cancel: finish 0
[15:37:33.430030] [canon_dr] sane_read: finish 0
[15:37:33.430140] [canon_dr] sane_read: start
[15:37:33.430158] [canon_dr] read_from_buffer: start
[15:37:33.430169] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3702784 bu:32768 pa:32768
[15:37:33.430190] [canon_dr] read_from_buffer: finished
[15:37:33.430204] [canon_dr] check_for_cancel: start
[15:37:33.430216] [canon_dr] check_for_cancel: finish 0
[15:37:33.430227] [canon_dr] sane_read: finish 0
[15:37:33.430337] [canon_dr] sane_read: start
[15:37:33.430354] [canon_dr] read_from_buffer: start
[15:37:33.430366] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3735552 bu:32768 pa:32768
[15:37:33.430384] [canon_dr] read_from_buffer: finished
[15:37:33.430397] [canon_dr] check_for_cancel: start
[15:37:33.430409] [canon_dr] check_for_cancel: finish 0
[15:37:33.430421] [canon_dr] sane_read: finish 0
[15:37:33.430530] [canon_dr] sane_read: start
[15:37:33.430545] [canon_dr] read_from_buffer: start
[15:37:33.430557] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3768320 bu:32768 pa:32768
[15:37:33.430576] [canon_dr] read_from_buffer: finished
[15:37:33.430588] [canon_dr] check_for_cancel: start
[15:37:33.430601] [canon_dr] check_for_cancel: finish 0
[15:37:33.430613] [canon_dr] sane_read: finish 0
[15:37:33.430723] [canon_dr] sane_read: start
[15:37:33.430738] [canon_dr] read_from_buffer: start
[15:37:33.430750] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3801088 bu:32768 pa:32768
[15:37:33.430768] [canon_dr] read_from_buffer: finished
[15:37:33.430781] [canon_dr] check_for_cancel: start
[15:37:33.430793] [canon_dr] check_for_cancel: finish 0
[15:37:33.430805] [canon_dr] sane_read: finish 0
[15:37:33.430913] [canon_dr] sane_read: start
[15:37:33.430928] [canon_dr] read_from_buffer: start
[15:37:33.430940] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3833856 bu:32768 pa:32768
[15:37:33.430959] [canon_dr] read_from_buffer: finished
[15:37:33.430971] [canon_dr] check_for_cancel: start
[15:37:33.430991] [canon_dr] check_for_cancel: finish 0
[15:37:33.431004] [canon_dr] sane_read: finish 0
[15:37:33.431114] [canon_dr] sane_read: start
[15:37:33.431129] [canon_dr] read_from_buffer: start
[15:37:33.431141] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3866624 bu:32768 pa:32768
[15:37:33.431159] [canon_dr] read_from_buffer: finished
[15:37:33.431172] [canon_dr] check_for_cancel: start
[15:37:33.431184] [canon_dr] check_for_cancel: finish 0
[15:37:33.431196] [canon_dr] sane_read: finish 0
[15:37:33.431317] [canon_dr] sane_read: start
[15:37:33.431331] [canon_dr] read_from_buffer: start
[15:37:33.431344] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3899392 bu:32768 pa:32768
[15:37:33.431361] [canon_dr] read_from_buffer: finished
[15:37:33.431374] [canon_dr] check_for_cancel: start
[15:37:33.431386] [canon_dr] check_for_cancel: finish 0
[15:37:33.431398] [canon_dr] sane_read: finish 0
[15:37:33.431510] [canon_dr] sane_read: start
[15:37:33.431524] [canon_dr] read_from_buffer: start
[15:37:33.431536] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3932160 bu:32768 pa:32768
[15:37:33.431554] [canon_dr] read_from_buffer: finished
[15:37:33.431566] [canon_dr] check_for_cancel: start
[15:37:33.431579] [canon_dr] check_for_cancel: finish 0
[15:37:33.431591] [canon_dr] sane_read: finish 0
[15:37:33.431717] [canon_dr] sane_read: start
[15:37:33.431732] [canon_dr] read_from_buffer: start
[15:37:33.431744] [canon_dr] read_from_buffer: si:0 to:3974600 tx:3964928 bu:32768 pa:9672
[15:37:33.431759] [canon_dr] read_from_buffer: finished
[15:37:33.431771] [canon_dr] check_for_cancel: start
[15:37:33.431783] [canon_dr] check_for_cancel: finish 0
[15:37:33.431794] [canon_dr] sane_read: finish 0
[15:37:33.431837] [canon_dr] sane_read: start
[15:37:33.431850] [canon_dr] sane_read: returning eof
scanimage: min/max graylevel value = 34/255
scanimage: read 3974600 bytes in total
Scanned page 1. (scanner status = 5)
Scanning page 2
[15:37:33.434138] [canon_dr] sane_start: start
[15:37:33.434157] [canon_dr] started=1, side=0, source=3
[15:37:33.434170] [canon_dr] update_i_params: start
[15:37:33.434182] [canon_dr] update_i_params: finish
[15:37:33.434194] [canon_dr] started=1, side=1, source=3
[15:37:33.434207] [canon_dr] check_for_cancel: start
[15:37:33.434219] [canon_dr] check_for_cancel: finish 0
[15:37:33.434231] [canon_dr] sane_start: finish 0
[15:37:33.434298] [canon_dr] sane_get_parameters: start
[15:37:33.434313] [canon_dr] sane_get_parameters: x: max=14784, page=10200, gpw=10200, res=200
[15:37:33.434326] [canon_dr] sane_get_parameters: y: max=20400, page=14033, gph=14033, res=200
[15:37:33.434338] [canon_dr] sane_get_parameters: area: tlx=0, brx=10200, tly=0, bry=14033
[15:37:33.434351] [canon_dr] sane_get_parameters: params: ppl=1700, Bpl=1700, lines=2338
[15:37:33.434363] [canon_dr] sane_get_parameters: params: format=0, depth=8, last=1
[15:37:33.434376] [canon_dr] sane_get_parameters: finish
scanimage: scanning image of size 1700x2338 pixels at 8 bits/pixel
scanimage: acquiring gray frame
[15:37:33.434412] [canon_dr] sane_read: start
[15:37:33.434425] [canon_dr] read_from_scanner: start
[15:37:33.434436] [canon_dr] read_from_scanner: si:1 to:3974600 rx:0 re:3974600 bu:2097152 pa:2096100 ex:0
[15:37:33.434485] [canon_dr] do_usb_cmd: start 1618234653 434485
[15:37:33.547976] [canon_dr] do_usb_cmd: finish 1618234653 547968
[15:37:33.548062] [canon_dr] read_from_scanner: got GOOD, returning GOOD 2096100
[15:37:33.548076] [canon_dr] copy_simplex: per-line copy
[15:37:33.549942] [canon_dr] copy_simplex: finished
[15:37:33.550531] [canon_dr] read_from_scanner: sto:3974600 srx:2096100 sef:0 uto:3974600 urx:0 uef:0
[15:37:33.550553] [canon_dr] read_from_scanner: finish
[15:37:33.550565] [canon_dr] read_from_buffer: start
[15:37:33.550577] [canon_dr] read_from_buffer: si:1 to:3974600 tx:0 bu:32768 pa:32768
[15:37:33.550595] [canon_dr] read_from_buffer: finished
[15:37:33.550609] [canon_dr] check_for_cancel: start
[15:37:33.550622] [canon_dr] check_for_cancel: finish 0
[15:37:33.550634] [canon_dr] sane_read: finish 0
[15:37:33.550794] [canon_dr] sane_read: start
[15:37:33.550811] [canon_dr] read_from_scanner: start
[15:37:33.550823] [canon_dr] read_from_scanner: si:1 to:3974600 rx:2096100 re:1878500 bu:2097152 pa:2096100 ex:0
[15:37:33.550851] [canon_dr] do_usb_cmd: start 1618234653 550850
[15:37:33.649248] [canon_dr] stat: status 2
[15:37:33.649332] [canon_dr] do_usb_clear: start
[15:37:33.749431] [canon_dr] do_usb_cmd: start 1618234653 749422
[15:37:33.750616] [canon_dr] do_usb_cmd: finish 1618234653 750615
[15:37:33.750643] [canon_dr] sense_handler: start
[15:37:33.750656] [canon_dr] Sense=00, ASC=00, ASCQ=00, EOM=0, ILI=1, info=0x035200
[15:37:33.750672] [canon_dr] No sense: EOM remainder:217600
[15:37:33.750684] [canon_dr] do_usb_clear: finish after RS
[15:37:33.750697] [canon_dr] in: short read, 2096100/1878500
[15:37:33.752312] [canon_dr] do_usb_cmd: finish 1618234653 752310
[15:37:33.752336] [canon_dr] read_from_scanner: got EOF, finishing 1878500
[15:37:33.752350] [canon_dr] copy_simplex: per-line copy
[15:37:33.754050] [canon_dr] copy_simplex: finished
[15:37:33.754604] [canon_dr] read_from_scanner: sto:3974600 srx:3974600 sef:1 uto:3974600 urx:32768 uef:0
[15:37:33.754627] [canon_dr] read_from_scanner: finish
[15:37:33.754639] [canon_dr] sane_read: side 1 counter 2
[15:37:33.754652] [canon_dr] read_from_buffer: start
[15:37:33.754664] [canon_dr] read_from_buffer: si:1 to:3974600 tx:32768 bu:32768 pa:32768
[15:37:33.754687] [canon_dr] read_from_buffer: finished
[15:37:33.754700] [canon_dr] check_for_cancel: start
[15:37:33.754712] [canon_dr] check_for_cancel: finish 0
[15:37:33.754725] [canon_dr] sane_read: finish 0
[15:37:33.754854] [canon_dr] sane_read: start
[15:37:33.754870] [canon_dr] read_from_buffer: start
[15:37:33.754882] [canon_dr] read_from_buffer: si:1 to:3974600 tx:65536 bu:32768 pa:32768
[15:37:33.754902] [canon_dr] read_from_buffer: finished
[15:37:33.754914] [canon_dr] check_for_cancel: start
[15:37:33.754925] [canon_dr] check_for_cancel: finish 0
[15:37:33.754936] [canon_dr] sane_read: finish 0
[15:37:33.755041] [canon_dr] sane_read: start
[15:37:33.755059] [canon_dr] read_from_buffer: start
[15:37:33.755071] [canon_dr] read_from_buffer: si:1 to:3974600 tx:98304 bu:32768 pa:32768
[15:37:33.755091] [canon_dr] read_from_buffer: finished
[15:37:33.755103] [canon_dr] check_for_cancel: start
[15:37:33.755114] [canon_dr] check_for_cancel: finish 0
[15:37:33.755125] [canon_dr] sane_read: finish 0
[15:37:33.755230] [canon_dr] sane_read: start
[15:37:33.755245] [canon_dr] read_from_buffer: start
[15:37:33.755258] [canon_dr] read_from_buffer: si:1 to:3974600 tx:131072 bu:32768 pa:32768
[15:37:33.755275] [canon_dr] read_from_buffer: finished
[15:37:33.755288] [canon_dr] check_for_cancel: start
[15:37:33.755300] [canon_dr] check_for_cancel: finish 0
[15:37:33.755312] [canon_dr] sane_read: finish 0
[15:37:33.755422] [canon_dr] sane_read: start
[15:37:33.755437] [canon_dr] read_from_buffer: start
[15:37:33.755449] [canon_dr] read_from_buffer: si:1 to:3974600 tx:163840 bu:32768 pa:32768
[15:37:33.755468] [canon_dr] read_from_buffer: finished
[15:37:33.755481] [canon_dr] check_for_cancel: start
[15:37:33.755493] [canon_dr] check_for_cancel: finish 0
[15:37:33.755505] [canon_dr] sane_read: finish 0
[15:37:33.755610] [canon_dr] sane_read: start
[15:37:33.755625] [canon_dr] read_from_buffer: start
[15:37:33.755637] [canon_dr] read_from_buffer: si:1 to:3974600 tx:196608 bu:32768 pa:32768
[15:37:33.755656] [canon_dr] read_from_buffer: finished
[15:37:33.755670] [canon_dr] check_for_cancel: start
[15:37:33.755682] [canon_dr] check_for_cancel: finish 0
[15:37:33.755694] [canon_dr] sane_read: finish 0
[15:37:33.755802] [canon_dr] sane_read: start
[15:37:33.755817] [canon_dr] read_from_buffer: start
[15:37:33.755829] [canon_dr] read_from_buffer: si:1 to:3974600 tx:229376 bu:32768 pa:32768
[15:37:33.755848] [canon_dr] read_from_buffer: finished
[15:37:33.755860] [canon_dr] check_for_cancel: start
[15:37:33.755872] [canon_dr] check_for_cancel: finish 0
[15:37:33.755885] [canon_dr] sane_read: finish 0
[15:37:33.755991] [canon_dr] sane_read: start
[15:37:33.756013] [canon_dr] read_from_buffer: start
[15:37:33.756025] [canon_dr] read_from_buffer: si:1 to:3974600 tx:262144 bu:32768 pa:32768
[15:37:33.756044] [canon_dr] read_from_buffer: finished
[15:37:33.756057] [canon_dr] check_for_cancel: start
[15:37:33.756069] [canon_dr] check_for_cancel: finish 0
[15:37:33.756081] [canon_dr] sane_read: finish 0
[15:37:33.756192] [canon_dr] sane_read: start
[15:37:33.756206] [canon_dr] read_from_buffer: start
[15:37:33.756219] [canon_dr] read_from_buffer: si:1 to:3974600 tx:294912 bu:32768 pa:32768
[15:37:33.756237] [canon_dr] read_from_buffer: finished
[15:37:33.756250] [canon_dr] check_for_cancel: start
[15:37:33.756262] [canon_dr] check_for_cancel: finish 0
[15:37:33.756274] [canon_dr] sane_read: finish 0
[15:37:33.756380] [canon_dr] sane_read: start
[15:37:33.756395] [canon_dr] read_from_buffer: start
[15:37:33.756407] [canon_dr] read_from_buffer: si:1 to:3974600 tx:327680 bu:32768 pa:32768
[15:37:33.756426] [canon_dr] read_from_buffer: finished
[15:37:33.756439] [canon_dr] check_for_cancel: start
[15:37:33.756451] [canon_dr] check_for_cancel: finish 0
[15:37:33.756463] [canon_dr] sane_read: finish 0
[15:37:33.756572] [canon_dr] sane_read: start
[15:37:33.756587] [canon_dr] read_from_buffer: start
[15:37:33.756599] [canon_dr] read_from_buffer: si:1 to:3974600 tx:360448 bu:32768 pa:32768
[15:37:33.756624] [canon_dr] read_from_buffer: finished
[15:37:33.756638] [canon_dr] check_for_cancel: start
[15:37:33.756650] [canon_dr] check_for_cancel: finish 0
[15:37:33.756662] [canon_dr] sane_read: finish 0
[15:37:33.756773] [canon_dr] sane_read: start
[15:37:33.756789] [canon_dr] read_from_buffer: start
[15:37:33.756800] [canon_dr] read_from_buffer: si:1 to:3974600 tx:393216 bu:32768 pa:32768
[15:37:33.756820] [canon_dr] read_from_buffer: finished
[15:37:33.756833] [canon_dr] check_for_cancel: start
[15:37:33.756843] [canon_dr] check_for_cancel: finish 0
[15:37:33.756858] [canon_dr] sane_read: finish 0
[15:37:33.756963] [canon_dr] sane_read: start
[15:37:33.756980] [canon_dr] read_from_buffer: start
[15:37:33.756992] [canon_dr] read_from_buffer: si:1 to:3974600 tx:425984 bu:32768 pa:32768
[15:37:33.757011] [canon_dr] read_from_buffer: finished
[15:37:33.757024] [canon_dr] check_for_cancel: start
[15:37:33.757036] [canon_dr] check_for_cancel: finish 0
[15:37:33.757048] [canon_dr] sane_read: finish 0
[15:37:33.757158] [canon_dr] sane_read: start
[15:37:33.757173] [canon_dr] read_from_buffer: start
[15:37:33.757185] [canon_dr] read_from_buffer: si:1 to:3974600 tx:458752 bu:32768 pa:32768
[15:37:33.757206] [canon_dr] read_from_buffer: finished
[15:37:33.757218] [canon_dr] check_for_cancel: start
[15:37:33.757230] [canon_dr] check_for_cancel: finish 0
[15:37:33.757242] [canon_dr] sane_read: finish 0
[15:37:33.757346] [canon_dr] sane_read: start
[15:37:33.757361] [canon_dr] read_from_buffer: start
[15:37:33.757374] [canon_dr] read_from_buffer: si:1 to:3974600 tx:491520 bu:32768 pa:32768
[15:37:33.757392] [canon_dr] read_from_buffer: finished
[15:37:33.757404] [canon_dr] check_for_cancel: start
[15:37:33.757416] [canon_dr] check_for_cancel: finish 0
[15:37:33.757428] [canon_dr] sane_read: finish 0
[15:37:33.757534] [canon_dr] sane_read: start
[15:37:33.757549] [canon_dr] read_from_buffer: start
[15:37:33.757562] [canon_dr] read_from_buffer: si:1 to:3974600 tx:524288 bu:32768 pa:32768
[15:37:33.757579] [canon_dr] read_from_buffer: finished
[15:37:33.757592] [canon_dr] check_for_cancel: start
[15:37:33.757604] [canon_dr] check_for_cancel: finish 0
[15:37:33.757616] [canon_dr] sane_read: finish 0
[15:37:33.757720] [canon_dr] sane_read: start
[15:37:33.757744] [canon_dr] read_from_buffer: start
[15:37:33.757756] [canon_dr] read_from_buffer: si:1 to:3974600 tx:557056 bu:32768 pa:32768
[15:37:33.757775] [canon_dr] read_from_buffer: finished
[15:37:33.757787] [canon_dr] check_for_cancel: start
[15:37:33.757800] [canon_dr] check_for_cancel: finish 0
[15:37:33.757812] [canon_dr] sane_read: finish 0
[15:37:33.757922] [canon_dr] sane_read: start
[15:37:33.757938] [canon_dr] read_from_buffer: start
[15:37:33.757957] [canon_dr] read_from_buffer: si:1 to:3974600 tx:589824 bu:32768 pa:32768
[15:37:33.757977] [canon_dr] read_from_buffer: finished
[15:37:33.757990] [canon_dr] check_for_cancel: start
[15:37:33.758002] [canon_dr] check_for_cancel: finish 0
[15:37:33.758015] [canon_dr] sane_read: finish 0
[15:37:33.758121] [canon_dr] sane_read: start
[15:37:33.758136] [canon_dr] read_from_buffer: start
[15:37:33.758148] [canon_dr] read_from_buffer: si:1 to:3974600 tx:622592 bu:32768 pa:32768
[15:37:33.758167] [canon_dr] read_from_buffer: finished
[15:37:33.758180] [canon_dr] check_for_cancel: start
[15:37:33.758191] [canon_dr] check_for_cancel: finish 0
[15:37:33.758204] [canon_dr] sane_read: finish 0
[15:37:33.758313] [canon_dr] sane_read: start
[15:37:33.758327] [canon_dr] read_from_buffer: start
[15:37:33.758339] [canon_dr] read_from_buffer: si:1 to:3974600 tx:655360 bu:32768 pa:32768
[15:37:33.758358] [canon_dr] read_from_buffer: finished
[15:37:33.758371] [canon_dr] check_for_cancel: start
[15:37:33.758383] [canon_dr] check_for_cancel: finish 0
[15:37:33.758395] [canon_dr] sane_read: finish 0
[15:37:33.758499] [canon_dr] sane_read: start
[15:37:33.758514] [canon_dr] read_from_buffer: start
[15:37:33.758525] [canon_dr] read_from_buffer: si:1 to:3974600 tx:688128 bu:32768 pa:32768
[15:37:33.758545] [canon_dr] read_from_buffer: finished
[15:37:33.758558] [canon_dr] check_for_cancel: start
[15:37:33.758570] [canon_dr] check_for_cancel: finish 0
[15:37:33.758582] [canon_dr] sane_read: finish 0
[15:37:33.758687] [canon_dr] sane_read: start
[15:37:33.758705] [canon_dr] read_from_buffer: start
[15:37:33.758716] [canon_dr] read_from_buffer: si:1 to:3974600 tx:720896 bu:32768 pa:32768
[15:37:33.758735] [canon_dr] read_from_buffer: finished
[15:37:33.758748] [canon_dr] check_for_cancel: start
[15:37:33.758759] [canon_dr] check_for_cancel: finish 0
[15:37:33.758771] [canon_dr] sane_read: finish 0
[15:37:33.758880] [canon_dr] sane_read: start
[15:37:33.758897] [canon_dr] read_from_buffer: start
[15:37:33.758908] [canon_dr] read_from_buffer: si:1 to:3974600 tx:753664 bu:32768 pa:32768
[15:37:33.758927] [canon_dr] read_from_buffer: finished
[15:37:33.758939] [canon_dr] check_for_cancel: start
[15:37:33.758951] [canon_dr] check_for_cancel: finish 0
[15:37:33.758964] [canon_dr] sane_read: finish 0
[15:37:33.759074] [canon_dr] sane_read: start
[15:37:33.759090] [canon_dr] read_from_buffer: start
[15:37:33.759102] [canon_dr] read_from_buffer: si:1 to:3974600 tx:786432 bu:32768 pa:32768
[15:37:33.759121] [canon_dr] read_from_buffer: finished
[15:37:33.759134] [canon_dr] check_for_cancel: start
[15:37:33.759146] [canon_dr] check_for_cancel: finish 0
[15:37:33.759158] [canon_dr] sane_read: finish 0
[15:37:33.759263] [canon_dr] sane_read: start
[15:37:33.759278] [canon_dr] read_from_buffer: start
[15:37:33.759290] [canon_dr] read_from_buffer: si:1 to:3974600 tx:819200 bu:32768 pa:32768
[15:37:33.759308] [canon_dr] read_from_buffer: finished
[15:37:33.759320] [canon_dr] check_for_cancel: start
[15:37:33.759333] [canon_dr] check_for_cancel: finish 0
[15:37:33.759345] [canon_dr] sane_read: finish 0
[15:37:33.759454] [canon_dr] sane_read: start
[15:37:33.759469] [canon_dr] read_from_buffer: start
[15:37:33.759482] [canon_dr] read_from_buffer: si:1 to:3974600 tx:851968 bu:32768 pa:32768
[15:37:33.759500] [canon_dr] read_from_buffer: finished
[15:37:33.759512] [canon_dr] check_for_cancel: start
[15:37:33.759524] [canon_dr] check_for_cancel: finish 0
[15:37:33.759535] [canon_dr] sane_read: finish 0
[15:37:33.759644] [canon_dr] sane_read: start
[15:37:33.759659] [canon_dr] read_from_buffer: start
[15:37:33.759671] [canon_dr] read_from_buffer: si:1 to:3974600 tx:884736 bu:32768 pa:32768
[15:37:33.759689] [canon_dr] read_from_buffer: finished
[15:37:33.759702] [canon_dr] check_for_cancel: start
[15:37:33.759714] [canon_dr] check_for_cancel: finish 0
[15:37:33.759726] [canon_dr] sane_read: finish 0
[15:37:33.759832] [canon_dr] sane_read: start
[15:37:33.759847] [canon_dr] read_from_buffer: start
[15:37:33.759859] [canon_dr] read_from_buffer: si:1 to:3974600 tx:917504 bu:32768 pa:32768
[15:37:33.759886] [canon_dr] read_from_buffer: finished
[15:37:33.759899] [canon_dr] check_for_cancel: start
[15:37:33.759911] [canon_dr] check_for_cancel: finish 0
[15:37:33.759923] [canon_dr] sane_read: finish 0
[15:37:33.760032] [canon_dr] sane_read: start
[15:37:33.760047] [canon_dr] read_from_buffer: start
[15:37:33.760059] [canon_dr] read_from_buffer: si:1 to:3974600 tx:950272 bu:32768 pa:32768
[15:37:33.760076] [canon_dr] read_from_buffer: finished
[15:37:33.760089] [canon_dr] check_for_cancel: start
[15:37:33.760101] [canon_dr] check_for_cancel: finish 0
[15:37:33.760113] [canon_dr] sane_read: finish 0
[15:37:33.760220] [canon_dr] sane_read: start
[15:37:33.760234] [canon_dr] read_from_buffer: start
[15:37:33.760246] [canon_dr] read_from_buffer: si:1 to:3974600 tx:983040 bu:32768 pa:32768
[15:37:33.760265] [canon_dr] read_from_buffer: finished
[15:37:33.760277] [canon_dr] check_for_cancel: start
[15:37:33.760289] [canon_dr] check_for_cancel: finish 0
[15:37:33.760301] [canon_dr] sane_read: finish 0
[15:37:33.760414] [canon_dr] sane_read: start
[15:37:33.760430] [canon_dr] read_from_buffer: start
[15:37:33.760442] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1015808 bu:32768 pa:32768
[15:37:33.760461] [canon_dr] read_from_buffer: finished
[15:37:33.760473] [canon_dr] check_for_cancel: start
[15:37:33.760485] [canon_dr] check_for_cancel: finish 0
[15:37:33.760497] [canon_dr] sane_read: finish 0
[15:37:33.760604] [canon_dr] sane_read: start
[15:37:33.760619] [canon_dr] read_from_buffer: start
[15:37:33.760630] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1048576 bu:32768 pa:32768
[15:37:33.760649] [canon_dr] read_from_buffer: finished
[15:37:33.760662] [canon_dr] check_for_cancel: start
[15:37:33.760674] [canon_dr] check_for_cancel: finish 0
[15:37:33.760686] [canon_dr] sane_read: finish 0
[15:37:33.760793] [canon_dr] sane_read: start
[15:37:33.760811] [canon_dr] read_from_buffer: start
[15:37:33.760823] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1081344 bu:32768 pa:32768
[15:37:33.760842] [canon_dr] read_from_buffer: finished
[15:37:33.760855] [canon_dr] check_for_cancel: start
[15:37:33.760866] [canon_dr] check_for_cancel: finish 0
[15:37:33.760877] [canon_dr] sane_read: finish 0
[15:37:33.760982] [canon_dr] sane_read: start
[15:37:33.760999] [canon_dr] read_from_buffer: start
[15:37:33.761012] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1114112 bu:32768 pa:32768
[15:37:33.761030] [canon_dr] read_from_buffer: finished
[15:37:33.761043] [canon_dr] check_for_cancel: start
[15:37:33.761055] [canon_dr] check_for_cancel: finish 0
[15:37:33.761067] [canon_dr] sane_read: finish 0
[15:37:33.761179] [canon_dr] sane_read: start
[15:37:33.761194] [canon_dr] read_from_buffer: start
[15:37:33.761206] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1146880 bu:32768 pa:32768
[15:37:33.761226] [canon_dr] read_from_buffer: finished
[15:37:33.761239] [canon_dr] check_for_cancel: start
[15:37:33.761251] [canon_dr] check_for_cancel: finish 0
[15:37:33.761263] [canon_dr] sane_read: finish 0
[15:37:33.761369] [canon_dr] sane_read: start
[15:37:33.761384] [canon_dr] read_from_buffer: start
[15:37:33.761396] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1179648 bu:32768 pa:32768
[15:37:33.761414] [canon_dr] read_from_buffer: finished
[15:37:33.761427] [canon_dr] check_for_cancel: start
[15:37:33.761439] [canon_dr] check_for_cancel: finish 0
[15:37:33.761451] [canon_dr] sane_read: finish 0
[15:37:33.761560] [canon_dr] sane_read: start
[15:37:33.761575] [canon_dr] read_from_buffer: start
[15:37:33.761587] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1212416 bu:32768 pa:32768
[15:37:33.761606] [canon_dr] read_from_buffer: finished
[15:37:33.761619] [canon_dr] check_for_cancel: start
[15:37:33.761630] [canon_dr] check_for_cancel: finish 0
[15:37:33.761643] [canon_dr] sane_read: finish 0
[15:37:33.761756] [canon_dr] sane_read: start
[15:37:33.761774] [canon_dr] read_from_buffer: start
[15:37:33.761786] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1245184 bu:32768 pa:32768
[15:37:33.761816] [canon_dr] read_from_buffer: finished
[15:37:33.761830] [canon_dr] check_for_cancel: start
[15:37:33.761843] [canon_dr] check_for_cancel: finish 0
[15:37:33.761855] [canon_dr] sane_read: finish 0
[15:37:33.761962] [canon_dr] sane_read: start
[15:37:33.761977] [canon_dr] read_from_buffer: start
[15:37:33.761989] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1277952 bu:32768 pa:32768
[15:37:33.762007] [canon_dr] read_from_buffer: finished
[15:37:33.762020] [canon_dr] check_for_cancel: start
[15:37:33.762031] [canon_dr] check_for_cancel: finish 0
[15:37:33.762044] [canon_dr] sane_read: finish 0
[15:37:33.762155] [canon_dr] sane_read: start
[15:37:33.762170] [canon_dr] read_from_buffer: start
[15:37:33.762182] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1310720 bu:32768 pa:32768
[15:37:33.762200] [canon_dr] read_from_buffer: finished
[15:37:33.762213] [canon_dr] check_for_cancel: start
[15:37:33.762225] [canon_dr] check_for_cancel: finish 0
[15:37:33.762237] [canon_dr] sane_read: finish 0
[15:37:33.762344] [canon_dr] sane_read: start
[15:37:33.762360] [canon_dr] read_from_buffer: start
[15:37:33.762372] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1343488 bu:32768 pa:32768
[15:37:33.762390] [canon_dr] read_from_buffer: finished
[15:37:33.762403] [canon_dr] check_for_cancel: start
[15:37:33.762415] [canon_dr] check_for_cancel: finish 0
[15:37:33.762427] [canon_dr] sane_read: finish 0
[15:37:33.762536] [canon_dr] sane_read: start
[15:37:33.762551] [canon_dr] read_from_buffer: start
[15:37:33.762563] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1376256 bu:32768 pa:32768
[15:37:33.762582] [canon_dr] read_from_buffer: finished
[15:37:33.762595] [canon_dr] check_for_cancel: start
[15:37:33.762606] [canon_dr] check_for_cancel: finish 0
[15:37:33.762619] [canon_dr] sane_read: finish 0
[15:37:33.762718] [canon_dr] sane_read: start
[15:37:33.762736] [canon_dr] read_from_buffer: start
[15:37:33.762748] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1409024 bu:32768 pa:32768
[15:37:33.762767] [canon_dr] read_from_buffer: finished
[15:37:33.762780] [canon_dr] check_for_cancel: start
[15:37:33.762791] [canon_dr] check_for_cancel: finish 0
[15:37:33.762803] [canon_dr] sane_read: finish 0
[15:37:33.762923] [canon_dr] sane_read: start
[15:37:33.762939] [canon_dr] read_from_buffer: start
[15:37:33.762952] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1441792 bu:32768 pa:32768
[15:37:33.762970] [canon_dr] read_from_buffer: finished
[15:37:33.762983] [canon_dr] check_for_cancel: start
[15:37:33.762994] [canon_dr] check_for_cancel: finish 0
[15:37:33.763007] [canon_dr] sane_read: finish 0
[15:37:33.763114] [canon_dr] sane_read: start
[15:37:33.763128] [canon_dr] read_from_buffer: start
[15:37:33.763140] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1474560 bu:32768 pa:32768
[15:37:33.763159] [canon_dr] read_from_buffer: finished
[15:37:33.763172] [canon_dr] check_for_cancel: start
[15:37:33.763183] [canon_dr] check_for_cancel: finish 0
[15:37:33.763196] [canon_dr] sane_read: finish 0
[15:37:33.763305] [canon_dr] sane_read: start
[15:37:33.763319] [canon_dr] read_from_buffer: start
[15:37:33.763332] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1507328 bu:32768 pa:32768
[15:37:33.763350] [canon_dr] read_from_buffer: finished
[15:37:33.763362] [canon_dr] check_for_cancel: start
[15:37:33.763374] [canon_dr] check_for_cancel: finish 0
[15:37:33.763386] [canon_dr] sane_read: finish 0
[15:37:33.763492] [canon_dr] sane_read: start
[15:37:33.763507] [canon_dr] read_from_buffer: start
[15:37:33.763519] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1540096 bu:32768 pa:32768
[15:37:33.763537] [canon_dr] read_from_buffer: finished
[15:37:33.763550] [canon_dr] check_for_cancel: start
[15:37:33.763562] [canon_dr] check_for_cancel: finish 0
[15:37:33.763574] [canon_dr] sane_read: finish 0
[15:37:33.763689] [canon_dr] sane_read: start
[15:37:33.763704] [canon_dr] read_from_buffer: start
[15:37:33.763716] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1572864 bu:32768 pa:32768
[15:37:33.763741] [canon_dr] read_from_buffer: finished
[15:37:33.763761] [canon_dr] check_for_cancel: start
[15:37:33.763774] [canon_dr] check_for_cancel: finish 0
[15:37:33.763786] [canon_dr] sane_read: finish 0
[15:37:33.763897] [canon_dr] sane_read: start
[15:37:33.763913] [canon_dr] read_from_buffer: start
[15:37:33.763925] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1605632 bu:32768 pa:32768
[15:37:33.763943] [canon_dr] read_from_buffer: finished
[15:37:33.763956] [canon_dr] check_for_cancel: start
[15:37:33.763967] [canon_dr] check_for_cancel: finish 0
[15:37:33.763979] [canon_dr] sane_read: finish 0
[15:37:33.764089] [canon_dr] sane_read: start
[15:37:33.764104] [canon_dr] read_from_buffer: start
[15:37:33.764116] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1638400 bu:32768 pa:32768
[15:37:33.764135] [canon_dr] read_from_buffer: finished
[15:37:33.764148] [canon_dr] check_for_cancel: start
[15:37:33.764160] [canon_dr] check_for_cancel: finish 0
[15:37:33.764173] [canon_dr] sane_read: finish 0
[15:37:33.764283] [canon_dr] sane_read: start
[15:37:33.764298] [canon_dr] read_from_buffer: start
[15:37:33.764310] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1671168 bu:32768 pa:32768
[15:37:33.764327] [canon_dr] read_from_buffer: finished
[15:37:33.764340] [canon_dr] check_for_cancel: start
[15:37:33.764352] [canon_dr] check_for_cancel: finish 0
[15:37:33.764364] [canon_dr] sane_read: finish 0
[15:37:33.764481] [canon_dr] sane_read: start
[15:37:33.764496] [canon_dr] read_from_buffer: start
[15:37:33.764508] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1703936 bu:32768 pa:32768
[15:37:33.764527] [canon_dr] read_from_buffer: finished
[15:37:33.764539] [canon_dr] check_for_cancel: start
[15:37:33.764551] [canon_dr] check_for_cancel: finish 0
[15:37:33.764563] [canon_dr] sane_read: finish 0
[15:37:33.764673] [canon_dr] sane_read: start
[15:37:33.764689] [canon_dr] read_from_buffer: start
[15:37:33.764701] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1736704 bu:32768 pa:32768
[15:37:33.764718] [canon_dr] read_from_buffer: finished
[15:37:33.764731] [canon_dr] check_for_cancel: start
[15:37:33.764742] [canon_dr] check_for_cancel: finish 0
[15:37:33.764754] [canon_dr] sane_read: finish 0
[15:37:33.764864] [canon_dr] sane_read: start
[15:37:33.764880] [canon_dr] read_from_buffer: start
[15:37:33.764892] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1769472 bu:32768 pa:32768
[15:37:33.764910] [canon_dr] read_from_buffer: finished
[15:37:33.764923] [canon_dr] check_for_cancel: start
[15:37:33.764935] [canon_dr] check_for_cancel: finish 0
[15:37:33.764947] [canon_dr] sane_read: finish 0
[15:37:33.765056] [canon_dr] sane_read: start
[15:37:33.765071] [canon_dr] read_from_buffer: start
[15:37:33.765083] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1802240 bu:32768 pa:32768
[15:37:33.765100] [canon_dr] read_from_buffer: finished
[15:37:33.765113] [canon_dr] check_for_cancel: start
[15:37:33.765124] [canon_dr] check_for_cancel: finish 0
[15:37:33.765136] [canon_dr] sane_read: finish 0
[15:37:33.765261] [canon_dr] sane_read: start
[15:37:33.765277] [canon_dr] read_from_buffer: start
[15:37:33.765289] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1835008 bu:32768 pa:32768
[15:37:33.765308] [canon_dr] read_from_buffer: finished
[15:37:33.765321] [canon_dr] check_for_cancel: start
[15:37:33.765333] [canon_dr] check_for_cancel: finish 0
[15:37:33.765345] [canon_dr] sane_read: finish 0
[15:37:33.765467] [canon_dr] sane_read: start
[15:37:33.765483] [canon_dr] read_from_buffer: start
[15:37:33.765495] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1867776 bu:32768 pa:32768
[15:37:33.765513] [canon_dr] read_from_buffer: finished
[15:37:33.765525] [canon_dr] check_for_cancel: start
[15:37:33.765537] [canon_dr] check_for_cancel: finish 0
[15:37:33.765550] [canon_dr] sane_read: finish 0
[15:37:33.765677] [canon_dr] sane_read: start
[15:37:33.765692] [canon_dr] read_from_buffer: start
[15:37:33.765705] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1900544 bu:32768 pa:32768
[15:37:33.765730] [canon_dr] read_from_buffer: finished
[15:37:33.765747] [canon_dr] check_for_cancel: start
[15:37:33.765768] [canon_dr] check_for_cancel: finish 0
[15:37:33.765780] [canon_dr] sane_read: finish 0
[15:37:33.765923] [canon_dr] sane_read: start
[15:37:33.765938] [canon_dr] read_from_buffer: start
[15:37:33.765950] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1933312 bu:32768 pa:32768
[15:37:33.765970] [canon_dr] read_from_buffer: finished
[15:37:33.765982] [canon_dr] check_for_cancel: start
[15:37:33.765994] [canon_dr] check_for_cancel: finish 0
[15:37:33.766007] [canon_dr] sane_read: finish 0
[15:37:33.766136] [canon_dr] sane_read: start
[15:37:33.766151] [canon_dr] read_from_buffer: start
[15:37:33.766163] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1966080 bu:32768 pa:32768
[15:37:33.766181] [canon_dr] read_from_buffer: finished
[15:37:33.766194] [canon_dr] check_for_cancel: start
[15:37:33.766206] [canon_dr] check_for_cancel: finish 0
[15:37:33.766218] [canon_dr] sane_read: finish 0
[15:37:33.766364] [canon_dr] sane_read: start
[15:37:33.766380] [canon_dr] read_from_buffer: start
[15:37:33.766392] [canon_dr] read_from_buffer: si:1 to:3974600 tx:1998848 bu:32768 pa:32768
[15:37:33.766411] [canon_dr] read_from_buffer: finished
[15:37:33.766423] [canon_dr] check_for_cancel: start
[15:37:33.766435] [canon_dr] check_for_cancel: finish 0
[15:37:33.766447] [canon_dr] sane_read: finish 0
[15:37:33.766563] [canon_dr] sane_read: start
[15:37:33.766582] [canon_dr] read_from_buffer: start
[15:37:33.766594] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2031616 bu:32768 pa:32768
[15:37:33.766612] [canon_dr] read_from_buffer: finished
[15:37:33.766625] [canon_dr] check_for_cancel: start
[15:37:33.766636] [canon_dr] check_for_cancel: finish 0
[15:37:33.766648] [canon_dr] sane_read: finish 0
[15:37:33.766778] [canon_dr] sane_read: start
[15:37:33.766795] [canon_dr] read_from_buffer: start
[15:37:33.766808] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2064384 bu:32768 pa:32768
[15:37:33.766827] [canon_dr] read_from_buffer: finished
[15:37:33.766840] [canon_dr] check_for_cancel: start
[15:37:33.766852] [canon_dr] check_for_cancel: finish 0
[15:37:33.766864] [canon_dr] sane_read: finish 0
[15:37:33.767009] [canon_dr] sane_read: start
[15:37:33.767024] [canon_dr] read_from_buffer: start
[15:37:33.767036] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2097152 bu:32768 pa:32768
[15:37:33.767055] [canon_dr] read_from_buffer: finished
[15:37:33.767068] [canon_dr] check_for_cancel: start
[15:37:33.767079] [canon_dr] check_for_cancel: finish 0
[15:37:33.767092] [canon_dr] sane_read: finish 0
[15:37:33.767205] [canon_dr] sane_read: start
[15:37:33.767220] [canon_dr] read_from_buffer: start
[15:37:33.767232] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2129920 bu:32768 pa:32768
[15:37:33.767251] [canon_dr] read_from_buffer: finished
[15:37:33.767263] [canon_dr] check_for_cancel: start
[15:37:33.767275] [canon_dr] check_for_cancel: finish 0
[15:37:33.767287] [canon_dr] sane_read: finish 0
[15:37:33.767422] [canon_dr] sane_read: start
[15:37:33.767437] [canon_dr] read_from_buffer: start
[15:37:33.767449] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2162688 bu:32768 pa:32768
[15:37:33.767468] [canon_dr] read_from_buffer: finished
[15:37:33.767481] [canon_dr] check_for_cancel: start
[15:37:33.767493] [canon_dr] check_for_cancel: finish 0
[15:37:33.767505] [canon_dr] sane_read: finish 0
[15:37:33.767643] [canon_dr] sane_read: start
[15:37:33.767659] [canon_dr] read_from_buffer: start
[15:37:33.767671] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2195456 bu:32768 pa:32768
[15:37:33.767690] [canon_dr] read_from_buffer: finished
[15:37:33.767702] [canon_dr] check_for_cancel: start
[15:37:33.767714] [canon_dr] check_for_cancel: finish 0
[15:37:33.767726] [canon_dr] sane_read: finish 0
[15:37:33.767852] [canon_dr] sane_read: start
[15:37:33.767868] [canon_dr] read_from_buffer: start
[15:37:33.767880] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2228224 bu:32768 pa:32768
[15:37:33.767899] [canon_dr] read_from_buffer: finished
[15:37:33.767912] [canon_dr] check_for_cancel: start
[15:37:33.767924] [canon_dr] check_for_cancel: finish 0
[15:37:33.767944] [canon_dr] sane_read: finish 0
[15:37:33.768073] [canon_dr] sane_read: start
[15:37:33.768088] [canon_dr] read_from_buffer: start
[15:37:33.768101] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2260992 bu:32768 pa:32768
[15:37:33.768119] [canon_dr] read_from_buffer: finished
[15:37:33.768133] [canon_dr] check_for_cancel: start
[15:37:33.768144] [canon_dr] check_for_cancel: finish 0
[15:37:33.768157] [canon_dr] sane_read: finish 0
[15:37:33.768270] [canon_dr] sane_read: start
[15:37:33.768285] [canon_dr] read_from_buffer: start
[15:37:33.768297] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2293760 bu:32768 pa:32768
[15:37:33.768315] [canon_dr] read_from_buffer: finished
[15:37:33.768328] [canon_dr] check_for_cancel: start
[15:37:33.768340] [canon_dr] check_for_cancel: finish 0
[15:37:33.768352] [canon_dr] sane_read: finish 0
[15:37:33.768488] [canon_dr] sane_read: start
[15:37:33.768504] [canon_dr] read_from_buffer: start
[15:37:33.768516] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2326528 bu:32768 pa:32768
[15:37:33.768535] [canon_dr] read_from_buffer: finished
[15:37:33.768548] [canon_dr] check_for_cancel: start
[15:37:33.768560] [canon_dr] check_for_cancel: finish 0
[15:37:33.768572] [canon_dr] sane_read: finish 0
[15:37:33.768703] [canon_dr] sane_read: start
[15:37:33.768722] [canon_dr] read_from_buffer: start
[15:37:33.768734] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2359296 bu:32768 pa:32768
[15:37:33.768753] [canon_dr] read_from_buffer: finished
[15:37:33.768765] [canon_dr] check_for_cancel: start
[15:37:33.768776] [canon_dr] check_for_cancel: finish 0
[15:37:33.768788] [canon_dr] sane_read: finish 0
[15:37:33.768911] [canon_dr] sane_read: start
[15:37:33.768928] [canon_dr] read_from_buffer: start
[15:37:33.768940] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2392064 bu:32768 pa:32768
[15:37:33.768959] [canon_dr] read_from_buffer: finished
[15:37:33.768972] [canon_dr] check_for_cancel: start
[15:37:33.768984] [canon_dr] check_for_cancel: finish 0
[15:37:33.768996] [canon_dr] sane_read: finish 0
[15:37:33.769129] [canon_dr] sane_read: start
[15:37:33.769145] [canon_dr] read_from_buffer: start
[15:37:33.769157] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2424832 bu:32768 pa:32768
[15:37:33.769175] [canon_dr] read_from_buffer: finished
[15:37:33.769188] [canon_dr] check_for_cancel: start
[15:37:33.769200] [canon_dr] check_for_cancel: finish 0
[15:37:33.769212] [canon_dr] sane_read: finish 0
[15:37:33.769332] [canon_dr] sane_read: start
[15:37:33.769347] [canon_dr] read_from_buffer: start
[15:37:33.769359] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2457600 bu:32768 pa:32768
[15:37:33.769379] [canon_dr] read_from_buffer: finished
[15:37:33.769392] [canon_dr] check_for_cancel: start
[15:37:33.769404] [canon_dr] check_for_cancel: finish 0
[15:37:33.769416] [canon_dr] sane_read: finish 0
[15:37:33.769533] [canon_dr] sane_read: start
[15:37:33.769548] [canon_dr] read_from_buffer: start
[15:37:33.769560] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2490368 bu:32768 pa:32768
[15:37:33.769579] [canon_dr] read_from_buffer: finished
[15:37:33.769592] [canon_dr] check_for_cancel: start
[15:37:33.769604] [canon_dr] check_for_cancel: finish 0
[15:37:33.769616] [canon_dr] sane_read: finish 0
[15:37:33.769745] [canon_dr] sane_read: start
[15:37:33.769763] [canon_dr] read_from_buffer: start
[15:37:33.769775] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2523136 bu:32768 pa:32768
[15:37:33.769794] [canon_dr] read_from_buffer: finished
[15:37:33.769807] [canon_dr] check_for_cancel: start
[15:37:33.769819] [canon_dr] check_for_cancel: finish 0
[15:37:33.769831] [canon_dr] sane_read: finish 0
[15:37:33.769957] [canon_dr] sane_read: start
[15:37:33.769972] [canon_dr] read_from_buffer: start
[15:37:33.769985] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2555904 bu:32768 pa:32768
[15:37:33.770004] [canon_dr] read_from_buffer: finished
[15:37:33.770017] [canon_dr] check_for_cancel: start
[15:37:33.770029] [canon_dr] check_for_cancel: finish 0
[15:37:33.770049] [canon_dr] sane_read: finish 0
[15:37:33.770183] [canon_dr] sane_read: start
[15:37:33.770198] [canon_dr] read_from_buffer: start
[15:37:33.770210] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2588672 bu:32768 pa:32768
[15:37:33.770230] [canon_dr] read_from_buffer: finished
[15:37:33.770242] [canon_dr] check_for_cancel: start
[15:37:33.770254] [canon_dr] check_for_cancel: finish 0
[15:37:33.770266] [canon_dr] sane_read: finish 0
[15:37:33.770389] [canon_dr] sane_read: start
[15:37:33.770404] [canon_dr] read_from_buffer: start
[15:37:33.770417] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2621440 bu:32768 pa:32768
[15:37:33.770435] [canon_dr] read_from_buffer: finished
[15:37:33.770447] [canon_dr] check_for_cancel: start
[15:37:33.770459] [canon_dr] check_for_cancel: finish 0
[15:37:33.770471] [canon_dr] sane_read: finish 0
[15:37:33.770615] [canon_dr] sane_read: start
[15:37:33.770631] [canon_dr] read_from_buffer: start
[15:37:33.770643] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2654208 bu:32768 pa:32768
[15:37:33.770662] [canon_dr] read_from_buffer: finished
[15:37:33.770675] [canon_dr] check_for_cancel: start
[15:37:33.770687] [canon_dr] check_for_cancel: finish 0
[15:37:33.770698] [canon_dr] sane_read: finish 0
[15:37:33.770816] [canon_dr] sane_read: start
[15:37:33.770834] [canon_dr] read_from_buffer: start
[15:37:33.770846] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2686976 bu:32768 pa:32768
[15:37:33.770863] [canon_dr] read_from_buffer: finished
[15:37:33.770876] [canon_dr] check_for_cancel: start
[15:37:33.770886] [canon_dr] check_for_cancel: finish 0
[15:37:33.770897] [canon_dr] sane_read: finish 0
[15:37:33.771034] [canon_dr] sane_read: start
[15:37:33.771050] [canon_dr] read_from_buffer: start
[15:37:33.771062] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2719744 bu:32768 pa:32768
[15:37:33.771081] [canon_dr] read_from_buffer: finished
[15:37:33.771093] [canon_dr] check_for_cancel: start
[15:37:33.771105] [canon_dr] check_for_cancel: finish 0
[15:37:33.771118] [canon_dr] sane_read: finish 0
[15:37:33.771235] [canon_dr] sane_read: start
[15:37:33.771251] [canon_dr] read_from_buffer: start
[15:37:33.771263] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2752512 bu:32768 pa:32768
[15:37:33.771281] [canon_dr] read_from_buffer: finished
[15:37:33.771293] [canon_dr] check_for_cancel: start
[15:37:33.771306] [canon_dr] check_for_cancel: finish 0
[15:37:33.771318] [canon_dr] sane_read: finish 0
[15:37:33.771436] [canon_dr] sane_read: start
[15:37:33.771451] [canon_dr] read_from_buffer: start
[15:37:33.771463] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2785280 bu:32768 pa:32768
[15:37:33.771481] [canon_dr] read_from_buffer: finished
[15:37:33.771494] [canon_dr] check_for_cancel: start
[15:37:33.771506] [canon_dr] check_for_cancel: finish 0
[15:37:33.771519] [canon_dr] sane_read: finish 0
[15:37:33.771633] [canon_dr] sane_read: start
[15:37:33.771648] [canon_dr] read_from_buffer: start
[15:37:33.771660] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2818048 bu:32768 pa:32768
[15:37:33.771679] [canon_dr] read_from_buffer: finished
[15:37:33.771691] [canon_dr] check_for_cancel: start
[15:37:33.771703] [canon_dr] check_for_cancel: finish 0
[15:37:33.771716] [canon_dr] sane_read: finish 0
[15:37:33.771840] [canon_dr] sane_read: start
[15:37:33.771856] [canon_dr] read_from_buffer: start
[15:37:33.771868] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2850816 bu:32768 pa:32768
[15:37:33.771886] [canon_dr] read_from_buffer: finished
[15:37:33.771899] [canon_dr] check_for_cancel: start
[15:37:33.771911] [canon_dr] check_for_cancel: finish 0
[15:37:33.771923] [canon_dr] sane_read: finish 0
[15:37:33.772042] [canon_dr] sane_read: start
[15:37:33.772057] [canon_dr] read_from_buffer: start
[15:37:33.772069] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2883584 bu:32768 pa:32768
[15:37:33.772087] [canon_dr] read_from_buffer: finished
[15:37:33.772100] [canon_dr] check_for_cancel: start
[15:37:33.772112] [canon_dr] check_for_cancel: finish 0
[15:37:33.772124] [canon_dr] sane_read: finish 0
[15:37:33.772266] [canon_dr] sane_read: start
[15:37:33.772281] [canon_dr] read_from_buffer: start
[15:37:33.772293] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2916352 bu:32768 pa:32768
[15:37:33.772312] [canon_dr] read_from_buffer: finished
[15:37:33.772325] [canon_dr] check_for_cancel: start
[15:37:33.772337] [canon_dr] check_for_cancel: finish 0
[15:37:33.772349] [canon_dr] sane_read: finish 0
[15:37:33.772480] [canon_dr] sane_read: start
[15:37:33.772495] [canon_dr] read_from_buffer: start
[15:37:33.772507] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2949120 bu:32768 pa:32768
[15:37:33.772525] [canon_dr] read_from_buffer: finished
[15:37:33.772538] [canon_dr] check_for_cancel: start
[15:37:33.772550] [canon_dr] check_for_cancel: finish 0
[15:37:33.772562] [canon_dr] sane_read: finish 0
[15:37:33.772689] [canon_dr] sane_read: start
[15:37:33.772708] [canon_dr] read_from_buffer: start
[15:37:33.772721] [canon_dr] read_from_buffer: si:1 to:3974600 tx:2981888 bu:32768 pa:32768
[15:37:33.772740] [canon_dr] read_from_buffer: finished
[15:37:33.772753] [canon_dr] check_for_cancel: start
[15:37:33.772764] [canon_dr] check_for_cancel: finish 0
[15:37:33.772775] [canon_dr] sane_read: finish 0
[15:37:33.772899] [canon_dr] sane_read: start
[15:37:33.772916] [canon_dr] read_from_buffer: start
[15:37:33.772928] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3014656 bu:32768 pa:32768
[15:37:33.772948] [canon_dr] read_from_buffer: finished
[15:37:33.772960] [canon_dr] check_for_cancel: start
[15:37:33.772972] [canon_dr] check_for_cancel: finish 0
[15:37:33.772984] [canon_dr] sane_read: finish 0
[15:37:33.773103] [canon_dr] sane_read: start
[15:37:33.773118] [canon_dr] read_from_buffer: start
[15:37:33.773130] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3047424 bu:32768 pa:32768
[15:37:33.773150] [canon_dr] read_from_buffer: finished
[15:37:33.773163] [canon_dr] check_for_cancel: start
[15:37:33.773175] [canon_dr] check_for_cancel: finish 0
[15:37:33.773187] [canon_dr] sane_read: finish 0
[15:37:33.773305] [canon_dr] sane_read: start
[15:37:33.773320] [canon_dr] read_from_buffer: start
[15:37:33.773332] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3080192 bu:32768 pa:32768
[15:37:33.773352] [canon_dr] read_from_buffer: finished
[15:37:33.773365] [canon_dr] check_for_cancel: start
[15:37:33.773377] [canon_dr] check_for_cancel: finish 0
[15:37:33.773389] [canon_dr] sane_read: finish 0
[15:37:33.773514] [canon_dr] sane_read: start
[15:37:33.773529] [canon_dr] read_from_buffer: start
[15:37:33.773542] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3112960 bu:32768 pa:32768
[15:37:33.773561] [canon_dr] read_from_buffer: finished
[15:37:33.773574] [canon_dr] check_for_cancel: start
[15:37:33.773586] [canon_dr] check_for_cancel: finish 0
[15:37:33.773598] [canon_dr] sane_read: finish 0
[15:37:33.773721] [canon_dr] sane_read: start
[15:37:33.773745] [canon_dr] read_from_buffer: start
[15:37:33.773757] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3145728 bu:32768 pa:32768
[15:37:33.773776] [canon_dr] read_from_buffer: finished
[15:37:33.773789] [canon_dr] check_for_cancel: start
[15:37:33.773801] [canon_dr] check_for_cancel: finish 0
[15:37:33.773813] [canon_dr] sane_read: finish 0
[15:37:33.773947] [canon_dr] sane_read: start
[15:37:33.773963] [canon_dr] read_from_buffer: start
[15:37:33.773975] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3178496 bu:32768 pa:32768
[15:37:33.773993] [canon_dr] read_from_buffer: finished
[15:37:33.774006] [canon_dr] check_for_cancel: start
[15:37:33.774017] [canon_dr] check_for_cancel: finish 0
[15:37:33.774030] [canon_dr] sane_read: finish 0
[15:37:33.774154] [canon_dr] sane_read: start
[15:37:33.774169] [canon_dr] read_from_buffer: start
[15:37:33.774181] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3211264 bu:32768 pa:32768
[15:37:33.774201] [canon_dr] read_from_buffer: finished
[15:37:33.774214] [canon_dr] check_for_cancel: start
[15:37:33.774226] [canon_dr] check_for_cancel: finish 0
[15:37:33.774238] [canon_dr] sane_read: finish 0
[15:37:33.774387] [canon_dr] sane_read: start
[15:37:33.774410] [canon_dr] read_from_buffer: start
[15:37:33.774423] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3244032 bu:32768 pa:32768
[15:37:33.774441] [canon_dr] read_from_buffer: finished
[15:37:33.774454] [canon_dr] check_for_cancel: start
[15:37:33.774466] [canon_dr] check_for_cancel: finish 0
[15:37:33.774478] [canon_dr] sane_read: finish 0
[15:37:33.774591] [canon_dr] sane_read: start
[15:37:33.774606] [canon_dr] read_from_buffer: start
[15:37:33.774618] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3276800 bu:32768 pa:32768
[15:37:33.774636] [canon_dr] read_from_buffer: finished
[15:37:33.774649] [canon_dr] check_for_cancel: start
[15:37:33.774660] [canon_dr] check_for_cancel: finish 0
[15:37:33.774672] [canon_dr] sane_read: finish 0
[15:37:33.774790] [canon_dr] sane_read: start
[15:37:33.774809] [canon_dr] read_from_buffer: start
[15:37:33.774821] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3309568 bu:32768 pa:32768
[15:37:33.774841] [canon_dr] read_from_buffer: finished
[15:37:33.774853] [canon_dr] check_for_cancel: start
[15:37:33.774863] [canon_dr] check_for_cancel: finish 0
[15:37:33.774874] [canon_dr] sane_read: finish 0
[15:37:33.775006] [canon_dr] sane_read: start
[15:37:33.775023] [canon_dr] read_from_buffer: start
[15:37:33.775035] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3342336 bu:32768 pa:32768
[15:37:33.775054] [canon_dr] read_from_buffer: finished
[15:37:33.775067] [canon_dr] check_for_cancel: start
[15:37:33.775079] [canon_dr] check_for_cancel: finish 0
[15:37:33.775091] [canon_dr] sane_read: finish 0
[15:37:33.775220] [canon_dr] sane_read: start
[15:37:33.775235] [canon_dr] read_from_buffer: start
[15:37:33.775247] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3375104 bu:32768 pa:32768
[15:37:33.775265] [canon_dr] read_from_buffer: finished
[15:37:33.775278] [canon_dr] check_for_cancel: start
[15:37:33.775290] [canon_dr] check_for_cancel: finish 0
[15:37:33.775302] [canon_dr] sane_read: finish 0
[15:37:33.775439] [canon_dr] sane_read: start
[15:37:33.775454] [canon_dr] read_from_buffer: start
[15:37:33.775466] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3407872 bu:32768 pa:32768
[15:37:33.775485] [canon_dr] read_from_buffer: finished
[15:37:33.775497] [canon_dr] check_for_cancel: start
[15:37:33.775508] [canon_dr] check_for_cancel: finish 0
[15:37:33.775521] [canon_dr] sane_read: finish 0
[15:37:33.775666] [canon_dr] sane_read: start
[15:37:33.775681] [canon_dr] read_from_buffer: start
[15:37:33.775693] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3440640 bu:32768 pa:32768
[15:37:33.775713] [canon_dr] read_from_buffer: finished
[15:37:33.775725] [canon_dr] check_for_cancel: start
[15:37:33.775737] [canon_dr] check_for_cancel: finish 0
[15:37:33.775749] [canon_dr] sane_read: finish 0
[15:37:33.775885] [canon_dr] sane_read: start
[15:37:33.775900] [canon_dr] read_from_buffer: start
[15:37:33.775912] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3473408 bu:32768 pa:32768
[15:37:33.775931] [canon_dr] read_from_buffer: finished
[15:37:33.775944] [canon_dr] check_for_cancel: start
[15:37:33.775955] [canon_dr] check_for_cancel: finish 0
[15:37:33.775967] [canon_dr] sane_read: finish 0
[15:37:33.776108] [canon_dr] sane_read: start
[15:37:33.776123] [canon_dr] read_from_buffer: start
[15:37:33.776135] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3506176 bu:32768 pa:32768
[15:37:33.776154] [canon_dr] read_from_buffer: finished
[15:37:33.776167] [canon_dr] check_for_cancel: start
[15:37:33.776179] [canon_dr] check_for_cancel: finish 0
[15:37:33.776191] [canon_dr] sane_read: finish 0
[15:37:33.776319] [canon_dr] sane_read: start
[15:37:33.776333] [canon_dr] read_from_buffer: start
[15:37:33.776345] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3538944 bu:32768 pa:32768
[15:37:33.776364] [canon_dr] read_from_buffer: finished
[15:37:33.776376] [canon_dr] check_for_cancel: start
[15:37:33.776388] [canon_dr] check_for_cancel: finish 0
[15:37:33.776400] [canon_dr] sane_read: finish 0
[15:37:33.776524] [canon_dr] sane_read: start
[15:37:33.776538] [canon_dr] read_from_buffer: start
[15:37:33.776557] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3571712 bu:32768 pa:32768
[15:37:33.776578] [canon_dr] read_from_buffer: finished
[15:37:33.776590] [canon_dr] check_for_cancel: start
[15:37:33.776602] [canon_dr] check_for_cancel: finish 0
[15:37:33.776614] [canon_dr] sane_read: finish 0
[15:37:33.776744] [canon_dr] sane_read: start
[15:37:33.776761] [canon_dr] read_from_buffer: start
[15:37:33.776772] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3604480 bu:32768 pa:32768
[15:37:33.776791] [canon_dr] read_from_buffer: finished
[15:37:33.776804] [canon_dr] check_for_cancel: start
[15:37:33.776815] [canon_dr] check_for_cancel: finish 0
[15:37:33.776827] [canon_dr] sane_read: finish 0
[15:37:33.776943] [canon_dr] sane_read: start
[15:37:33.776958] [canon_dr] read_from_buffer: start
[15:37:33.776970] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3637248 bu:32768 pa:32768
[15:37:33.776989] [canon_dr] read_from_buffer: finished
[15:37:33.777002] [canon_dr] check_for_cancel: start
[15:37:33.777013] [canon_dr] check_for_cancel: finish 0
[15:37:33.777025] [canon_dr] sane_read: finish 0
[15:37:33.777130] [canon_dr] sane_read: start
[15:37:33.777145] [canon_dr] read_from_buffer: start
[15:37:33.777157] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3670016 bu:32768 pa:32768
[15:37:33.777176] [canon_dr] read_from_buffer: finished
[15:37:33.777189] [canon_dr] check_for_cancel: start
[15:37:33.777201] [canon_dr] check_for_cancel: finish 0
[15:37:33.777213] [canon_dr] sane_read: finish 0
[15:37:33.777344] [canon_dr] sane_read: start
[15:37:33.777359] [canon_dr] read_from_buffer: start
[15:37:33.777371] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3702784 bu:32768 pa:32768
[15:37:33.777392] [canon_dr] read_from_buffer: finished
[15:37:33.777404] [canon_dr] check_for_cancel: start
[15:37:33.777416] [canon_dr] check_for_cancel: finish 0
[15:37:33.777428] [canon_dr] sane_read: finish 0
[15:37:33.777568] [canon_dr] sane_read: start
[15:37:33.777583] [canon_dr] read_from_buffer: start
[15:37:33.777595] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3735552 bu:32768 pa:32768
[15:37:33.777613] [canon_dr] read_from_buffer: finished
[15:37:33.777626] [canon_dr] check_for_cancel: start
[15:37:33.777638] [canon_dr] check_for_cancel: finish 0
[15:37:33.777650] [canon_dr] sane_read: finish 0
[15:37:33.781776] [canon_dr] sane_read: start
[15:37:33.781806] [canon_dr] read_from_buffer: start
[15:37:33.781819] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3768320 bu:32768 pa:32768
[15:37:33.781838] [canon_dr] read_from_buffer: finished
[15:37:33.781851] [canon_dr] check_for_cancel: start
[15:37:33.781864] [canon_dr] check_for_cancel: finish 0
[15:37:33.781876] [canon_dr] sane_read: finish 0
[15:37:33.782003] [canon_dr] sane_read: start
[15:37:33.782019] [canon_dr] read_from_buffer: start
[15:37:33.782031] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3801088 bu:32768 pa:32768
[15:37:33.782051] [canon_dr] read_from_buffer: finished
[15:37:33.782063] [canon_dr] check_for_cancel: start
[15:37:33.782076] [canon_dr] check_for_cancel: finish 0
[15:37:33.782089] [canon_dr] sane_read: finish 0
[15:37:33.782211] [canon_dr] sane_read: start
[15:37:33.782227] [canon_dr] read_from_buffer: start
[15:37:33.782239] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3833856 bu:32768 pa:32768
[15:37:33.782259] [canon_dr] read_from_buffer: finished
[15:37:33.782272] [canon_dr] check_for_cancel: start
[15:37:33.782284] [canon_dr] check_for_cancel: finish 0
[15:37:33.782296] [canon_dr] sane_read: finish 0
[15:37:33.782408] [canon_dr] sane_read: start
[15:37:33.782423] [canon_dr] read_from_buffer: start
[15:37:33.782435] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3866624 bu:32768 pa:32768
[15:37:33.782454] [canon_dr] read_from_buffer: finished
[15:37:33.782466] [canon_dr] check_for_cancel: start
[15:37:33.782478] [canon_dr] check_for_cancel: finish 0
[15:37:33.782490] [canon_dr] sane_read: finish 0
[15:37:33.782597] [canon_dr] sane_read: start
[15:37:33.782612] [canon_dr] read_from_buffer: start
[15:37:33.782624] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3899392 bu:32768 pa:32768
[15:37:33.782653] [canon_dr] read_from_buffer: finished
[15:37:33.782667] [canon_dr] check_for_cancel: start
[15:37:33.782678] [canon_dr] check_for_cancel: finish 0
[15:37:33.782690] [canon_dr] sane_read: finish 0
[15:37:33.782802] [canon_dr] sane_read: start
[15:37:33.782820] [canon_dr] read_from_buffer: start
[15:37:33.782832] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3932160 bu:32768 pa:32768
[15:37:33.782850] [canon_dr] read_from_buffer: finished
[15:37:33.782863] [canon_dr] check_for_cancel: start
[15:37:33.782873] [canon_dr] check_for_cancel: finish 0
[15:37:33.782884] [canon_dr] sane_read: finish 0
[15:37:33.783002] [canon_dr] sane_read: start
[15:37:33.783018] [canon_dr] read_from_buffer: start
[15:37:33.783028] [canon_dr] read_from_buffer: si:1 to:3974600 tx:3964928 bu:32768 pa:9672
[15:37:33.783043] [canon_dr] read_from_buffer: finished
[15:37:33.783055] [canon_dr] check_for_cancel: start
[15:37:33.783067] [canon_dr] check_for_cancel: finish 0
[15:37:33.783080] [canon_dr] sane_read: finish 0
[15:37:33.783123] [canon_dr] sane_read: start
[15:37:33.783136] [canon_dr] sane_read: returning eof
scanimage: min/max graylevel value = 35/255
scanimage: read 3974600 bytes in total
Scanned page 2. (scanner status = 5)
Scanning page 3
[15:37:33.785430] [canon_dr] sane_start: start
[15:37:33.785448] [canon_dr] started=1, side=1, source=3
[15:37:33.785461] [canon_dr] update_i_params: start
[15:37:33.785474] [canon_dr] update_i_params: finish
[15:37:33.785486] [canon_dr] clean_params: start
[15:37:33.785498] [canon_dr] clean_params: finish
[15:37:33.785511] [canon_dr] object_position: start
[15:37:33.785523] [canon_dr] object_position: load
[15:37:33.785536] [canon_dr] do_usb_cmd: start 1618234653 785535
[15:37:33.793366] [canon_dr] stat: clearing error 'Error during device I/O'
[15:37:33.793414] [canon_dr] do_usb_clear: start
[15:37:33.893510] [canon_dr] do_usb_clear: clear halt
[15:37:33.894486] [canon_dr] do_usb_cmd: start 1618234653 894484
[15:37:33.896116] [canon_dr] do_usb_cmd: finish 1618234653 896115
[15:37:33.896141] [canon_dr] sense_handler: start
[15:37:33.896154] [canon_dr] Sense=0x5, ASC=0x3a, ASCQ=00, EOM=0, ILI=0, info=00000000
[15:37:33.896170] [canon_dr] Illegal request: no paper
[15:37:33.896182] [canon_dr] do_usb_clear: finish after RS
[15:37:33.896195] [canon_dr] stat: bad RS status, 7
[15:37:33.896209] [canon_dr] sane_start: ERROR: cannot load page
[15:37:33.896222] [canon_dr] sane_start: error 7
scanimage: sane_start: Document feeder out of documents
Batch terminated, 2 pages scanned
[15:37:33.896247] [canon_dr] sane_cancel: start
[15:37:33.896259] [canon_dr] check_for_cancel: start
[15:37:33.896272] [canon_dr] check_for_cancel: already cancelled
[15:37:33.896284] [canon_dr] check_for_cancel: finish 2
[15:37:33.896296] [canon_dr] sane_cancel: finish
[15:37:33.896309] [canon_dr] sane_close: start
[15:37:33.896322] [canon_dr] disconnect_fd: start
[15:37:33.896334] [canon_dr] disconnecting usb device
[15:37:33.896398] [canon_dr] disconnect_fd: finish
[15:37:33.896414] [canon_dr] image_buffers: start
[15:37:33.896426] [canon_dr] image_buffers: free buffer 0.
[15:37:33.897184] [canon_dr] image_buffers: free buffer 1.
[15:37:33.897776] [canon_dr] image_buffers: finish
[15:37:33.897798] [canon_dr] offset_buffers: start
[15:37:33.897810] [canon_dr] offset_buffers: finish
[15:37:33.897822] [canon_dr] gain_buffers: start
[15:37:33.897835] [canon_dr] gain_buffers: finish
[15:37:33.897847] [canon_dr] sane_close: finish
[15:37:33.901610] [canon_dr] sane_exit: start
[15:37:33.901640] [canon_dr] disconnect_fd: start
[15:37:33.901653] [canon_dr] disconnect_fd: finish
[15:37:33.901666] [canon_dr] sane_exit: finish
-- 
Cadets were humping in the corridors, a party of outraged Senators roamed
Krane barracks, everyone, including me, questioned orders, ...
Law and order.
	David Feintuch - Fisherman's Hope.