SCM

[#315489] Epson Perfection 1260 inserts long delay (about 50..100s) before scanning (plustek)

View Trackers | Bugs | Export CSV

Date:
2016-09-08 16:00
Priority:
3
State:
Open
Submitted by:
Frieder Ferlemann (frief-guest)
Assigned to:
Gerhard Jaeger (gja-guest)
Category:
backends (drivers)
Group:
None
Resolution:
None
Summary:
Epson Perfection 1260 inserts long delay (about 50..100s) before scanning (plustek)

Detailed description
Hi,

and thanks for sane! With the above scanner there is a long delay before each of the scans. The scans themselves are fine.

Did an strace with timestamps:
strace -t scanimage 2>scanimage.strace >test

and a delay of about 50..100 seconds (see 21:48:43) is typical:

21:48:43 ioctl(11, USBDEVFS_SUBMITURB, 0x24ea010) = 0
21:48:43 poll([{fd=6, events=POLLIN}, {fd=8, events=POLLIN}, {fd=10, events=POLLIN}, {fd=11, events=POLLOUT}], 4, 60000) = 1 ([{fd=11, revents=POLLOUT}])
21:48:43 ioctl(11, USBDEVFS_REAPURBNDELAY, 0x7fff5d8a7ff8) = 0
21:48:43 timerfd_settime(10, 0, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
21:48:43 ioctl(11, USBDEVFS_REAPURBNDELAY, 0x7fff5d8a7ff8) = -1 EAGAIN (Resource temporarily unavailable)
21:48:43 timerfd_settime(10, TFD_TIMER_ABSTIME, {it_interval={0, 0}, it_value={3283, 999047000}}, NULL) = 0
21:48:43 ioctl(11, USBDEVFS_SUBMITURB, 0x24ea010) = 0
21:48:43 poll([{fd=6, events=POLLIN}, {fd=8, events=POLLIN}, {fd=10, events=POLLIN}, {fd=11, events=POLLOUT}], 4, 60000) = 1 ([{fd=11, revents=POLLOUT}])
21:48:43 ioctl(11, USBDEVFS_REAPURBNDELAY, 0x7fff5d8a7ff8) = 0
21:48:43 timerfd_settime(10, 0, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
21:48:43 ioctl(11, USBDEVFS_REAPURBNDELAY, 0x7fff5d8a7ff8) = -1 EAGAIN (Resource temporarily unavailable)
21:48:43 rt_sigprocmask(SIG_BLOCK, [ALRM], [], 8) = 0
21:48:43 setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
21:48:43 brk(0x253d000) = 0x253d000
21:48:43 pipe([12, 13]) = 0
21:48:43 rt_sigaction(SIGPIPE, NULL, {0x406d50, [PIPE], SA_RESTORER|SA_RESTART, 0x7f63fcad5120}, 8) = 0
21:48:43 mmap(NULL, 8392704, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x7f63f9eb9000
21:48:43 mprotect(0x7f63f9eb9000, 4096, PROT_NONE) = 0
21:48:43 clone(child_stack=0x7f63fa6b8ff0, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, parent_tidptr=0x7f63fa6b99d0, tls=0x7f63fa6b9700, child_tidptr=0x7f63fa6b99d0) = 817
21:48:43 nanosleep({0, 1000}, NULL) = 0
21:48:43 rt_sigaction(SIGCHLD, {0x7f63fb6c8180, [CHLD], SA_RESTORER|SA_RESTART, 0x7f63fcad5120}, {SIG_DFL, [], 0}, 8) = 0
21:48:43 fstat(1, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
21:48:43 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f63fd726000
21:48:43 read(12, "y8\t\0\0\0\0\0", 8) = 8
21:50:25 read(12, "@AK@@G=;A<<B?;E>@D;<B><C;=><<>26"..., 32768) = 6060
21:50:25 write(1, "P6\n# SANE data follows\n202 150\n2"..., 4096) = 4096
21:50:25 read(12, "\311\314\317\354\354\367\355\354\370\355\357\371\356\361\372\357\363\373\357\361\374\357\363\372\360\361\372\357\362\373\355\362"..., 32768) = 4848
21:50:25 write(1, "\367\353\355\370\354\355\367\355\357\370\357\357\370\355\356\370\354\357\371\354\356\364\354\356\367\355\355\371\354\355\370\352"..., 4096) = 4096
21:50:25 read(12, "\313\320\317\352\355\366\347\355\371\356\356\373\354\360\372\357\362\373\360\360\373\362\362\374\357\363\375\356\363\377\362\363"..., 32768) = 1818
21:50:25 write(1, "\362\365\376\363\366\375\360\363\374\361\363\375\360\361\373\357\364\376\361\364\375\360\362\377\360\363\374\360\362\373\357\362"..., 4096) = 4096
21:50:25 read(12, "\313\316\317\353\351\366\353\353\370\354\356\371\355\362\372\355\361\373\357\361\374\361\363\373\362\363\372\361\363\376\361\361"..., 32768) = 5454
21:50:26 write(1, "\366\377\363\365\376\362\366\377\364\366\377\361\367\377\363\365\375\363\364\377\362\366\377\363\366\376\364\365\377\364\365\377"..., 4096) = 4096
21:50:26 read(12, "\313\312\312\351\352\362\351\354\366\354\355\372\355\357\367\355\360\371\357\361\372\357\362\375\354\362\373\357\364\373\362\363"..., 32768) = 606

different run:
21:54:51 read(12, "!4\t\0\0\0\0\0", 8) = 8
21:56:27 read(12, "\25,-\35%&\27!\37\30 \34\26\"\35\30\35\26\26\27\27\27\30\31\24\26\31\24\30\27\17\31"..., 32768) = 6060

and an earlier run with shorter delay:
21:40:29 read(12, "\0009\t\0\0\0\0\0", 8) = 8
21:41:18 read(12, "\27+)\23\33 \25\37\32\25\36\31\24\35\33\24\33\27\23\27\24\24\24\27\22\24\24\23\26\31\23\26"..., 32768) = 6060


Tried with openSUSE 1.0.24 and 1.0.25.git20160528 (https://software.opensuse.org/package/sane-backends), /usr/lib64/sane/libsane-plustek_pp.so.1.0.26 and various scan programs (scanimage, xsane, skanlite, simple-scan) with same behaviour.
According

Can I/should I provide more info?

Greetings,

Followups: Sort comments antichronologically

No Followups Have Been Posted

Attached Files:

Changes:

Field Old Value Date By
assigned_tonone2016-09-25 14:23kitno-guest
Powered By FusionForge