cups-1.2.10-7.fc6 /var/log/cups/error_log says: E [29/Jun/2007:12:46:09 +0200] [Job 12079] Out of paper! strace gives endless: write(5, "\200T\310\300\00516385\370\250R\3014\0\370\242\301`\0\370"..., 8192) = -1 EAGAIN (Resource temporarily unavailable) This nonstop repeated write probably eats all CPU.
Please try the test update: yum --enablerepo=updates-testing update 'cups*' Does that fix the problem? (This is similar to bug #241589.)
cups-1.2.10-9.fc6, this fd '5' is /dev/usb/lp0 Nothing has changed, still usb backend eats CPU.
How are you measuring the CPU usage of the task? Please attach a strace of the 'usb://...' process while it is using lots of CPU.
I measuring it with 'top', when "Out of paper!" appears in log top shows "usb" command with ~95% of CPU usage.
1. lp -d Lexmark file.pdf 2. ps axf 3. 5514 ? R 0:26 usb:/dev/usb/lp0 ....... 4. strace -tt -p 5514 2>strace.log I have cut strace log because in a few seconds it grown to 45MB :) and it's all the same messages. error_log: I [03/Jul/2007:22:45:06 +0200] Adding start banner page "none" to job 12353. I [03/Jul/2007:22:45:06 +0200] Adding end banner page "none" to job 12353. I [03/Jul/2007:22:45:06 +0200] Job 12353 queued on "Lexmark" by "root". I [03/Jul/2007:22:45:06 +0200] Started backend /usr/lib/cups/backend/usb (PID 5514) for job 12353. E [03/Jul/2007:22:45:12 +0200] [Job 12353] Out of paper!
Created attachment 158475 [details] strace -tt -p 5514 2>strace.log
Problem understood. The usb:/dev/usb/...-type URI causes us not to be using select(), and that path is behaving incorrectly. A test update package, 1.2.11-1.fc6, will shortly be available (probably later this week). When it is, please try it out: yum --enablerepo=updates-testing update 'cups*' or, if you'd like to try out the packages sooner (although they won't be signed), I've put them here: http://cyberelk.net/tim/data/tmp/cups/
cups-1.2.11-1.fc6. Patch looks ok :) BTW: Do you plan to send this patch upstream? I am asking because of "linux_usb_paperout_hack" ;) Just for info, strace: 18:13:54.510192 write(5, "\2d\310\230\2534\337\233\213\r\236\350\347\364\253P\255"..., 8192) = -1 EAGAIN (Resource temporarily unavailable) 18:13:54.510488 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0 18:13:54.510674 rt_sigaction(SIGCHLD, NULL, {SIG_DFL}, 8) = 0 18:13:54.510976 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 18:13:54.511209 nanosleep({1, 0}, {1, 0}) = 0 18:13:55.512969 write(5, "\2d\310\230\2534\337\233\213\r\236\350\347\364\253P\255"..., 8192) = -1 EAGAIN (Resource temporarily unavailable) 18:13:55.513267 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0 18:13:55.513452 rt_sigaction(SIGCHLD, NULL, {SIG_DFL}, 8) = 0 18:13:55.513732 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 18:13:55.513928 nanosleep({1, 0}, {1, 0}) = 0
Great. No, I don't plan to send this patch upstream, but a much simpler one once the kernel is fixed to do this stuff itself (see bug #236736).
Thanks for info, and for fixing this bug.
cups-1.2.11-3.fc7 has been pushed to the Fedora 7 testing repository. If problems still persist, please make note of it in this bug report.
cups-1.2.12-1.fc7 has been pushed to the Fedora 7 testing repository. If problems still persist, please make note of it in this bug report.
cups-1.2.12-1.fc7 has been pushed to the Fedora 7 stable repository. If problems still persist, please make note of it in this bug report.