Description of problem: There are a lot messages in /var/log/cups/access_log every 3-4 seconds "Renew-Subscription successful-ok" when kde-print-manager installed. Version-Release number of selected component (if applicable): kde-print-manager-0.2.0-6.fc18.i686 Actual results: localhost - - [10/Dec/2012:04:38:02 +0200] "POST / HTTP/1.1" 200 437 Create-Printer-Subscription successful-ok localhost - - [10/Dec/2012:04:38:05 +0200] "POST / HTTP/1.1" 200 183 Renew-Subscription successful-ok localhost - - [10/Dec/2012:04:38:09 +0200] "POST / HTTP/1.1" 200 183 Renew-Subscription successful-ok localhost - - [10/Dec/2012:04:38:12 +0200] "POST / HTTP/1.1" 200 183 Renew-Subscription successful-ok localhost - - [10/Dec/2012:04:38:16 +0200] "POST / HTTP/1.1" 200 183 Renew-Subscription successful-ok localhost - - [10/Dec/2012:04:38:19 +0200] "POST / HTTP/1.1" 200 183 Renew-Subscription successful-ok localhost - - [10/Dec/2012:04:38:23 +0200] "POST / HTTP/1.1" 200 183 Renew-Subscription successful-ok localhost - - [10/Dec/2012:04:38:26 +0200] "POST / HTTP/1.1" 200 183 Renew-Subscription successful-ok localhost - - [10/Dec/2012:04:38:30 +0200] "POST / HTTP/1.1" 200 183 Renew-Subscription successful-ok localhost - - [10/Dec/2012:04:38:33 +0200] "POST / HTTP/1.1" 200 183 Renew-Subscription successful-ok localhost - - [10/Dec/2012:04:38:37 +0200] "POST / HTTP/1.1" 200 183 Renew-Subscription successful-ok localhost - - [10/Dec/2012:04:38:40 +0200] "POST / HTTP/1.1" 200 183 Renew-Subscription successful-ok localhost - - [10/Dec/2012:04:38:44 +0200] "POST / HTTP/1.1" 200 183 Renew-Subscription successful-ok localhost - - [10/Dec/2012:04:38:47 +0200] "POST / HTTP/1.1" 200 183 Renew-Subscription successful-ok localhost - - [10/Dec/2012:04:38:51 +0200] "POST / HTTP/1.1" 200 183 Renew-Subscription successful-ok localhost - - [10/Dec/2012:04:38:54 +0200] "POST / HTTP/1.1" 200 183 Renew-Subscription successful-ok localhost - - [10/Dec/2012:04:38:58 +0200] "POST / HTTP/1.1" 200 183 Renew-Subscription successful-ok localhost - - [10/Dec/2012:04:39:01 +0200] "POST / HTTP/1.1" 200 183 Renew-Subscription successful-ok localhost - - [10/Dec/2012:04:39:05 +0200] "POST / HTTP/1.1" 200 183 Renew-Subscription successful-ok Expected results: No spam in /var/log/cups/access_log Additional info: No spam if kde-print-manager uninstalled.
It's CUPS which spams this logfile with those useless messages, reassigning.
If I disable and stop cups.service I got the same spam in .xsession-errors which made by kde-print-manager but not CUPS: plasma-desktop(1659) KCupsConnection::renewDBusSubscription: Request failed 1280 plasma-desktop(1659) KCupsConnection::renewDBusSubscription: Request failed 1280 plasma-desktop(1659) KCupsConnection::renewDBusSubscription: Request failed 1280 plasma-desktop(1659) KCupsConnection::renewDBusSubscription: Request failed 1280 plasma-desktop(1659) KCupsConnection::renewDBusSubscription: Request failed 1280 plasma-desktop(1659) KCupsConnection::renewDBusSubscription: Request failed 1280 plasma-desktop(1659) KCupsConnection::renewDBusSubscription: Request failed 1280 plasma-desktop(1659) KCupsConnection::renewDBusSubscription: Request failed 1280 plasma-desktop(1659) KCupsConnection::renewDBusSubscription: Request failed 1280 plasma-desktop(1659) KCupsConnection::renewDBusSubscription: Request failed 1280
Well, of course, if you try to run a CUPS frontend without CUPS running, you'll get error messages… The real problem is the spam in the non-error case.
Frontend error message can be shown once but not every 3 seconds.
There is other problem with CUPS activation. If kde-print-manager is not installed then cups.service activated after first access to printing. But with kde-print-manager installed cups.service activated even if printing never used, so the idea to activate only when it needed don't works.
Why is it renewing the subscription every 3 seconds? That's far too often. You can specify the lease duration you want when you create the lease. Do that, and remember to renew it before that time is up. That's what GNOME does. Alternatively, you get an error code when the lease has expired: simply create a new subscription at that point. That's how system-config-printer handles it. Renewing every 3 seconds is a pointless waste of power.
The code in question seemingly does set/use #define RENEW_INTERVAL 3500 #define SUBSCRIPTION_DURATION 3600 except... i think I see the problem, // Creates the timer that will renew the DBus subscription m_renewTimer = new QTimer; m_renewTimer->setInterval(RENEW_INTERVAL); According to http://qt-project.org/doc/qt-4.8/qtimer.html#interval-prop, "This property holds the timeout interval in milliseconds." doh! Initial tests to patch this to use RENEW_INTERVAL*1000 seems to make it behave. I'll whip up a test build here shortly...
We've got a fix in-hand, nominating NTH to avoid spamming /var/log/cups/access_log and users' ~/.xsession-errors
kde-print-manager-0.2.0-8.fc18 has been submitted as an update for Fedora 18. https://admin.fedoraproject.org/updates/kde-print-manager-0.2.0-8.fc18
kde-print-manager-0.2.0-7.fc17 has been submitted as an update for Fedora 17. https://admin.fedoraproject.org/updates/kde-print-manager-0.2.0-7.fc17
Package kde-print-manager-0.2.0-8.fc18: * should fix your issue, * was pushed to the Fedora 18 testing repository, * should be available at your local mirror within two days. Update it with: # su -c 'yum update --enablerepo=updates-testing kde-print-manager-0.2.0-8.fc18' as soon as you are able to. Please go to the following url: https://admin.fedoraproject.org/updates/FEDORA-2012-20386/kde-print-manager-0.2.0-8.fc18 then log in and leave karma (feedback).
Now enew-Subscription messages appeared once per hour. localhost - - [15/Dec/2012:15:07:40 -0500] "POST / HTTP/1.1" 200 315 Create-Printer-Subscription successful-ok localhost - - [15/Dec/2012:15:07:40 -0500] "POST / HTTP/1.1" 200 156 Cancel-Subscription successful-ok localhost - - [15/Dec/2012:15:07:40 -0500] "POST / HTTP/1.1" 200 441 Create-Printer-Subscription successful-ok localhost - - [15/Dec/2012:16:06:00 -0500] "POST / HTTP/1.1" 200 187 Renew-Subscription successful-ok
That's exactly what the patch is designed to do (renew every 3500 seconds rather than every 3500 milliseconds).
Discussed at 2012-12-17 NTH review meeting: http://meetbot.fedoraproject.org/fedora-bugzappers/2012-12-17/f18final-blocker-review-5.2012-12-17-16.40.log.txt . Accepted as NTH - this affects KDE lives, it could potentially overflow memory or something icky like that.
kde-print-manager-0.2.0-8.fc18 has been pushed to the Fedora 18 stable repository. If problems still persist, please make note of it in this bug report.
kde-print-manager-0.2.0-7.fc17 has been pushed to the Fedora 17 stable repository. If problems still persist, please make note of it in this bug report.