7:32 a.m.
Tim - I'm continuing the thread "CUPS 1.4.4 slow - problem checklist?" I
started in the cups.general forum, here. I'll summarise the problem.
We have two cupsd processes (staff, student) on a Slackware Linux 13.1
print server running as a virtual machine on server hardware.
I found that only two users running system-config-printer-applet
('scpa') on their Linux desktops was enough to take cupsd CPU% (as
measured by top(1)) to 99% - just one will take it to 60-80%. I don't
know what version of scpa we have as default on our system, but version
1.2.5 from the 13th October also causes the problem.
Running scpa as 'system-config-printer-applet --debug', I saw:
$ /usr/share/system-config-printer/system-config-printer.py --debug
Connected as user john
refresh
<monitor.Monitor instance at 0x9b13eec>: CUPS IPP error (1025,
'client-error-forbidden')
Created subscription -1
<monitor.Monitor instance at 0x9b13eec>: printers and jobs lists provided
update_jobs
Authentication pass: 1
Authentication: password callback set
Authentication pass: 1
Authentication: password callback set
Authentication pass: 1
Authentication: password callback set
get_notifications
refresh
<monitor.Monitor instance at 0x9b13eec>: CUPS IPP error (1025,
'client-error-forbidden')
Created subscription -1
<monitor.Monitor instance at 0x989eeec>: printers and jobs lists provided
update_jobs
get_notifications
refresh
<monitor.Monitor instance at 0x989eeec>: CUPS IPP error (1025,
'client-error-forbidden')
...
Now, to discuss the problems:
1. You wrote:
> <monitor.Monitor instance at 0x9b13eec>: CUPS IPP error
(1025, 'client-er=
ror-forbidden')
> Created subscription -1
This looks like IPP-Create-Subscription is not allowed for this client,
due to the way CUPS is configured. Subscriptions are more efficient for
this sort of application because it can be told about relevant changes
rather than having to fetch the entire list each time:
I attach our server's cupsd.conf file (bowdlerised with "whatever"s!),
which contains:
# Set the default printer/job policies...
<Policy default>
# Job-related operations must be done by the owner or an adminstrator...
# Note that we need to 'Allow from localhost' for Windows LPR printing
<Limit Send-Document Send-URI Hold-Job Release-Job Restart-Job Purge-Jobs
Set-Job-Attributes Create-Job-Subscription Renew-Subscription
Cancel-Subscription
Get-Notifications Reprocess-Job Cancel-Job Cancel-Current-Job
Suspend-Current-Job
Resume-Job CUPS-Move-Job Get-Job-Attributes
CUPS-Authenticate-Job>
Order allow,deny
AuthType Default # required to force authentication
Require user @OWNER @SYSTEM
Allow from localhost
Satisfy any
</Limit>
That has Create-Job-Subscription etc permissions for all users. Perhaps
the 'Allow from localhost' - i.e. the print server - ought to be applied
more selectively, but it was there to allow print jobs coming in by
cups-lpr from Windows systems to proceed. I see from the CUPS document
'Managing Operations Policies' -
http://www.cups.org/documentation.php/doc-1.4/policies.html - that I'd
missed various subscription-related policies (Yes: I have it; No - I
don't have it):
Create-Printer-Subscription No
Create-Job-Subscription Yes
Get-Subscription-Attributes No
Get-Subscriptions No
Renew-Subscription Yes
Cancel-Subscription Yes
Get-Notifications Yes
Send-Notifications No
Do I need all of the ones I have not used? I think I took the original
set from an example CUPS configuration file, long ago.
2. You also wrote:
> <monitor.Monitor instance at 0x9b13eec>: printers and jobs
lists provided
But how often is it doing that? Does it happen continuously even when
there is no activity, or does it only happen whenever there is some
change in the status of a job?
It does seem to happen continually even when there is no activity, as
fast as CUPS can respond - which is presumably why the CPU% of cupsd
rises to 99%.
John A. Murdie
9:36 a.m.
On Wed, 2010-10-20 at 13:32 +0100, John A. Murdie wrote:
>> <monitor.Monitor instance at 0x9b13eec>: CUPS IPP
error (1025, 'client-er=
> ror-forbidden')
>> Created subscription -1
>
> This looks like IPP-Create-Subscription is not allowed for this client,
> due to the way CUPS is configured. Subscriptions are more efficient for
> this sort of application because it can be told about relevant changes
> rather than having to fetch the entire list each time:
I attach our server's cupsd.conf file (bowdlerised with "whatever"s!),
which contains:
> # Set the default printer/job policies...
> <Policy default>
>
> # Job-related operations must be done by the owner or an adminstrator...
> # Note that we need to 'Allow from localhost' for Windows LPR printing
> <Limit Send-Document Send-URI Hold-Job Release-Job Restart-Job Purge-Jobs
> Set-Job-Attributes Create-Job-Subscription Renew-Subscription
Cancel-Subscription
> Get-Notifications Reprocess-Job Cancel-Job Cancel-Current-Job
Suspend-Current-Job
> Resume-Job CUPS-Move-Job Get-Job-Attributes
CUPS-Authenticate-Job>
> Order allow,deny
> AuthType Default # required to force authentication
> Require user @OWNER @SYSTEM
> Allow from localhost
> Satisfy any
> </Limit>
So yes, Create-Job-Subscription and Create-Printer-Subscription require
authentication. Currently system-config-printer's CUPS monitor module
does not support using authentication for that, and it isn't really
meant to handle automatic updating if it can't use subscriptions.
It does seem to happen continually even when there is no activity, as
fast as CUPS can respond - which is presumably why the CPU% of cupsd
rises to 99%.
I think I might have found the problem. When it fails to get
notifications (because there is no subscription to use), it refreshes
the entire list of printers and jobs... and tries to create another
subscription.
Should be fixed upstream now, in that it won't try to automatically
update printers and jobs if subscriptions cannot be used.
Would you be able to try it out? Just down monitor.py from the current
1.2.x branch and use it as a replacement for the one in 1.2.5:
http://git.fedorahosted.org/git/?p=system-config-printer.git;a=blob_plain...
Thanks,
Tim.
*/
11:58 a.m.
On 20/10/10 15:36, Tim Waugh wrote:
So yes, Create-Job-Subscription and Create-Printer-Subscription
require
authentication. Currently system-config-printer's CUPS monitor module
does not support using authentication for that, and it isn't really
meant to handle automatic updating if it can't use subscriptions.
> It does seem to happen continually even when there is no activity, as
> fast as CUPS can respond - which is presumably why the CPU% of cupsd
> rises to 99%.
I think I might have found the problem. When it fails to get
notifications (because there is no subscription to use), it refreshes
the entire list of printers and jobs... and tries to create another
subscription.
Should be fixed upstream now, in that it won't try to automatically
update printers and jobs if subscriptions cannot be used.
Would you be able to try it out? Just down monitor.py from the current
1.2.x branch and use it as a replacement for the one in 1.2.5:
http://git.fedorahosted.org/git/?p=system-config-printer.git;a=blob_plain...
Thanks,
Tim.
I tried 1.2.5 with the new monitor.py before adding
Create-Printer-Subscription (we already had Create-Job-Subscription as
my lisy showed) and saw:
./system-config-printer-applet --debug
system-config-printer-applet: failed to start NewPrinterNotification service
refresh
<monitor.Monitor instance at 0x9320dac>: CUPS IPP error (1025,
'client-error-forbidden')
<monitor.Monitor instance at 0x9320dac>: printers and jobs lists provided
Upset printers: set([])
open notifications: 0
num_jobs: 0
num_jobs_when_hidden: 0
update_jobs
Got 0 jobs, asked for 1
update_jobs
Then I added Create-Printer-Subscription to the cupsd.conf and restarted
cupsd and tried again:
; ./system-config-printer-applet --debug
system-config-printer-applet: failed to start NewPrinterNotification service
refresh
Created subscription 3, events=['printer-added', 'printer-deleted',
'printer-state-changed', 'job-created', 'job-completed',
'job-stopped',
'job-state-changed', 'job-progress']
Next notifications fetch in 1s
<monitor.Monitor instance at 0x9befdac>: printers and jobs lists provided
Upset printers: set([])
open notifications: 0
num_jobs: 0
num_jobs_when_hidden: 0
Deferred get_notifications by 200ms
update_jobs
Got 0 jobs, asked for 1
update_jobs
get_notifications
update_jobs
Next notifications fetch in 60s
get_notifications
1 job-created Job created.
{'job-impressions-completed': 0,
'job-name': u'291010.pdf',
'job-state': 4,
'job-state-reasons': u'job-hold-until-specified',
'notify-charset': u'utf-8',
'notify-job-id': 22968,
'notify-natural-langugage': u'en-us',
'notify-printer-uri': u'ipp://ness.cs.york.ac.uk:631/printers/cp001',
'notify-sequence-number': 1,
'notify-subscribed-event': u'job-created',
'notify-subscription-id': 3,
'notify-text': u'Job created.',
'printer-is-accepting-jobs': True,
'printer-name': u'cp001',
'printer-state': 3,
'printer-state-reasons': [u'none'],
'printer-up-time': 1287593697}
2 printer-state-changed Printer "cp001" state changed to password.
{'notify-charset': u'utf-8',
'notify-natural-langugage': u'en-us',
'notify-printer-uri': u'ipp://ness.cs.york.ac.uk:631/printers/cp001',
'notify-sequence-number': 2,
'notify-subscribed-event': u'printer-state-changed',
'notify-subscription-id': 3,
'notify-text': u'Printer "cp001" state changed to password.',
'printer-is-accepting-jobs': True,
'printer-name': u'cp001',
'printer-state': 4,
'printer-state-reasons': [u'none'],
'printer-up-time': 1287593697}
3 job-state-changed Job #22968 started.
{'job-impressions-completed': 0,
'job-name': u'291010.pdf',
'job-state': 5,
'job-state-reasons': u'job-printing',
'notify-charset': u'utf-8',
'notify-job-id': 22968,
'notify-natural-langugage': u'en-us',
'notify-printer-uri': u'ipp://ness.cs.york.ac.uk:631/printers/cp001',
'notify-sequence-number': 3,
'notify-subscribed-event': u'job-state-changed',
'notify-subscription-id': 3,
'notify-text': u'Job #22968 started.',
'printer-is-accepting-jobs': True,
'printer-name': u'cp001',
'printer-state': 4,
'printer-state-reasons': [u'none'],
'printer-up-time': 1287593697}
update_jobs
<monitor.Monitor instance at 0x9befdac>: printer `cp001' has event
`printer-state-changed'
Next notifications fetch in 60s
...
However, the %CPU of the cupsd doesn't rise greatly as it did before.
Though I never see the GUI display of printers, which is weird!
I'd like to know where the '60s' interval comes from - is it hard-wired
in the code, or something configurable in CUPS?
12:25 p.m.
On Wed, 2010-10-20 at 17:58 +0100, John A. Murdie wrote:
However, the %CPU of the cupsd doesn't rise greatly as it did
before.
Though I never see the GUI display of printers, which is weird!
You don't see any printer icons?
I'd like to know where the '60s' interval comes from - is
it hard-wired
in the code, or something configurable in CUPS?
It is set by CUPS, although I think clients (such as
system-config-printer) can specify how frequently they would like to
connect when they create subscriptions.
Tim.
*/
3:19 p.m.
On 20/10/10 18:25, Tim Waugh wrote:
On Wed, 2010-10-20 at 17:58 +0100, John A. Murdie wrote:
> However, the %CPU of the cupsd doesn't rise greatly as it did before.
> Though I never see the GUI display of printers, which is weird!
You don't see any printer icons?
No, no printer icon window appears.
4:54 a.m.
On Wed, 2010-10-20 at 21:19 +0100, John A. Murdie wrote:
No, no printer icon window appears.
Ah, it's because it is the applet we're debugging. All that does is
register (and initially, hide) a status icon. So that's expected.
Seems like it's solved? Thanks for helping to pinpoint it.
Tim.
*/
8:47 a.m.
On 21/10/10 10:54, Tim Waugh wrote:
On Wed, 2010-10-20 at 21:19 +0100, John A. Murdie wrote:
> No, no printer icon window appears.
Ah, it's because it is the applet we're debugging. All that does is
register (and initially, hide) a status icon. So that's expected.
Seems like it's solved? Thanks for helping to pinpoint it.
Tim.
*/
Yes, solved, I think. By the way - the version we have is 1.2.2; I
didn't think to do a 'Help' -> 'About' until later!
Oddly, we have seen similar behaviour (but apparently with a different
cause) from gnome-cups-manager.
Many thanks for your assistance.
4946
days inactive
4947
days old
system-config-printer-devel@lists.fedorahosted.org
6 comments
2 participants
participants (2)
-
John A. Murdie -
Tim Waugh