I discovered this problem as soon as I started upgrading and installing computers with F26. By testing each new version of cups-filters on a F25 system, I determined that the problem started with cups-filters-1.12.0. cups-browsed starts creating queues from the printers it finds, but then it gets a message that cups has modified the printer, so it goes through the whole routine of updating the queue again. This repeats endlessly with cups running at 100% CPU. Possibly related is that this is the first version of cups-filters that causes cups to create colord profiles for the printers. I can't find any way to disable that function, so I can't test it. From /var/log/cups/cups-browsed.log: Sat Sep 2 15:00:52 2017 Print queue KONICA-MINOLTA is for remote CUPS queue(s) and we get notifications from CUPS, using implicit class dev ice URI implicitclass:KONICA-MINOLTA Sat Sep 2 15:00:52 2017 Loaded PPD file /tmp/cupsEGLsUc for printer KONICA-MINOLTA from server server.local:631! Sat Sep 2 15:00:52 2017 Editing PPD file /tmp/cupsEGLsUc for printer KONICA-MINOLTA, setting the option defaults of the previous cups-brows ed session and inhibiting client-side filtering of the job, saving the resulting PPD in /tmp/cups9PWJcN. Sat Sep 2 15:00:52 2017 Non-raw queue KONICA-MINOLTA with PPD file: /tmp/cups9PWJcN Sat Sep 2 15:01:01 2017 Unable to create/modify CUPS queue (Success)! Sat Sep 2 15:01:01 2017 checking queues in 1s Sat Sep 2 15:01:01 2017 [CUPS Notification] Printer modified: Printer "KONICA-MINOLTA" modified by "root". Sat Sep 2 15:01:01 2017 Settings of printer KONICA-MINOLTA got modified, doing backup. Sat Sep 2 15:01:01 2017 Recording printer options for KONICA-MINOLTA to /var/cache/cups/cups-browsed-options-KONICA-MINOLTA Sat Sep 2 15:01:02 2017 Processing printer list ... Sat Sep 2 15:01:02 2017 Creating/Updating CUPS queue for KONICA-MINOLTA Sat Sep 2 15:01:02 2017 Queue has 0 duplicates Sat Sep 2 15:01:02 2017 Loading saved printer options for KONICA-MINOLTA from /var/cache/cups/cups-browsed-options-KONICA-MINOLTA Sat Sep 2 15:01:02 2017 Loading following option settings for printer KONICA-MINOLTA: Sat Sep 2 15:01:02 2017 AutoTrapping=False [..snip..] Sat Sep 2 15:01:02 2017 TransparencyInterleave=None Sat Sep 2 15:01:02 2017 Sat Sep 2 15:01:02 2017 Print queue KONICA-MINOLTA is for remote CUPS queue(s) and we get notifications from CUPS, using implicit class device URI implicitclass:KONICA-MINOLTA Sat Sep 2 15:01:02 2017 Loaded PPD file /tmp/cups0hL9fY for printer KONICA-MINOLTA from server server.local:631! Sat Sep 2 15:01:02 2017 Editing PPD file /tmp/cups0hL9fY for printer KONICA-MINOLTA, setting the option defaults of the previous cups-browsed session and inhibiting client-side filtering of the job, saving the resulting PPD in /tmp/cupsgCWDv9. Sat Sep 2 15:01:02 2017 Non-raw queue KONICA-MINOLTA with PPD file: /tmp/cupsgCWDv9 Sat Sep 2 15:01:05 2017 Unable to create/modify CUPS queue (Success)! Sat Sep 2 15:01:05 2017 checking queues in 7s
After debugging the problem, it turns out that it's the same problem that was supposed to be fixed! The problem is this line: Sat Sep 2 15:01:05 2017 Unable to create/modify CUPS queue (Success)! I patched mine to check the string for "Success" and not fail in that case. Now, there is no more problem.
Hi Samuel, thank you for reporting this issue. Where or when did you see this issue is fixed? I think the problem is with functions cupsLastError() and cupsLastErrorString() - cupsLastError seems to return error, but cupsLastErrorString() returns success. Would you mind finding out what value return cupsLastError()?
It's not fixed. I even recompiled 1.14 for F26 and it has the same problem. I've just made my own package with a patch to avoid that problem by checking the string as well as the return code. I will try to get that value for you later today.
The code I get from cupsLastError() is 1280.
(In reply to Samuel Sieb from comment #1) > After debugging the problem, it turns out that it's the same problem that > was supposed to be fixed! I understood from that this is problem should be fixed in some later release or already have report in which is said it is fixed. That's why I asked you to tell me you source of information on which you based your sentence. 1280 means 0x0500 in hexadecimal and it is code for IPP_STATUS_ERROR_INTERNAL, which is CUPS server internal error. Would you mind sending cupsd debug log? (set it by $ su -c 'cupsctl LogLevel=debug2', restart service and send me output of $ journalctl -u cups --since=<time when cups-browsed started sending messages same as in comment#0>) And cups-browsed debug log? Other thing is why it ends in infinite loop. Whole part of code is for loop, which iterates on remote_printers global variable in cups-browsed.c. Would you mind finding out what is in remote_printers array?
Hi, We have the same problem on Fedora 26 and Fedora 27. We had to disable the cups-browsed service on all our machines. How can we help you to debug this problem ? You will find logs attached. Regards, Fabrice
Created attachment 1399205 [details] cups logs
Hi, I believe we had the same issue before. If I remember correctly this is due to the fact that it takes cups too long to create the queue (for "complicated" ppd's, like we had on our KONICA's). cups-browsed has already timed out and retries to create the queue. This causes the loop. In newer versions this can be worked around by increasing the timeout: HttpLocalTimeout (and HttpRemoteTimeout) setting in cups-browsed.conf We now use 'HttpLocalTimeout 30' in our cups-browsed.conf to work around this issue. Regards, Rik
Thanks for the feedback. It is actually Konica printer that are used on our internal network. We applied the 'HttpLocalTimeout 30' settings in cups-browsed.conf and the problem was solved... No more cups process taking 100% of CPU. Best regards, Fabrice
Thank you Rik for advice! I'm sorry, Fabrice, I couldn't help you with it. I created "Known Issues" at Fedora Wiki https://fedoraproject.org/wiki/How_to_debug_printing_problems#Known_issues . I hope it helps others. I'll backport HttpLocalTimeout and HttpRemoteTimeout directives to F26, so users will be able to set these directives. General solution (setting HttpLocalTimeout to defined value by default) would have slowed other users, so I will only backport these two directives and users will have to set it properly, if needed.
cups-filters-1.13.4-4.fc26 has been submitted as an update to Fedora 26. https://bodhi.fedoraproject.org/updates/FEDORA-2018-5726321974
cups-filters-1.13.4-4.fc26 has been pushed to the Fedora 26 testing repository. If problems still persist, please make note of it in this bug report. See https://fedoraproject.org/wiki/QA:Updates_Testing for instructions on how to install test updates. You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2018-5726321974
cups-filters-1.13.4-4.fc26 has been pushed to the Fedora 26 stable repository. If problems still persist, please make note of it in this bug report.
Why would it be a problem to increase the default timeout by a bit? This will likely be an issue for many people and they won't have any idea how to solve it.