[cups.general] (1.5.4) cupsd dies while trying to display a list of completed jobs

Michael Sweet msweet at apple.com
Thu Oct 18 16:03:48 PDT 2012


Alex,

It would be useful to get a stack trace from the crash - if you have gdb on your system you can run:

    sudo gdb /usr/sbin/cupsd
    run -f
    bt

and then send the output back in your reply.


On 2012-10-18, at 5:29 PM, Alex Korobkin <korobkin+cups at gmail.com> wrote:

> Hi team, 
> 
> I've recently updated my Ubuntu 10.04 print server to CUPS 1.5.4 and encountered this problem: 
> 
> When i try to get a list of completed jobs via web-interface (Jobs > Show Completed Jobs), server prints page header, waits for about a minute, then displays nothing below the header. 
> 
> With help of top I see that as soon as i hit "Show Completed Jobs" button, CUPS starts to use 100% of CPU, then gets killed and respawned with a new PID. error_log shows that CUPS receives job listing request, finds out it needs to process 749 completed jobs from 53 printers, reads their attributes one by one, and then suddenly dies as if something has killed it.
> 
> Is there an internal timeout (60 sec?) that would kill cupsd in this situation? 
> Is there a way to make CUPS process these jobs page by page in order to reply faster, instead of going through all those completed jobs? 
> 
> Here is an excerpt from the error_log (debug2):
> 
> == Server starts: 
> I [18/Oct/2012:19:47:52 +0000] Resuming new connection processing...
> <snip>
> D [18/Oct/2012:19:47:52 +0000] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
> <snip>
> D [18/Oct/2012:19:47:52 +0000] Discarding unused server-started event...
> <snip>
> D [18/Oct/2012:19:47:52 +0000] Report: clients=1
> D [18/Oct/2012:19:47:52 +0000] Report: jobs=749
> D [18/Oct/2012:19:47:52 +0000] Report: jobs-active=0
> D [18/Oct/2012:19:47:52 +0000] Report: printers=53
> D [18/Oct/2012:19:47:52 +0000] Report: printers-implicit=0
> D [18/Oct/2012:19:47:52 +0000] Report: stringpool-string-count=648288
> D [18/Oct/2012:19:47:52 +0000] Report: stringpool-alloc-bytes=39360
> D [18/Oct/2012:19:47:52 +0000] Report: stringpool-total-bytes=11849752
> <snip>
> 
> == Server tries to create a report on completed jobs:
> d [18/Oct/2012:19:49:48 +0000] get_jobs: job->id=167215, dest="james-color", username="johndoe", state_value=9, attrs=(nil)
> D [18/Oct/2012:19:49:48 +0000] [Job 167215] Loading attributes...
> d [18/Oct/2012:19:49:48 +0000] cupsdCheckGroup(username="anonymous", user=(nil), groupname="OWNER")
> d [18/Oct/2012:19:49:48 +0000] get_md5_password(username="anonymous", group="OWNER", passwd=0x7fff8fb6d3b0)
> d [18/Oct/2012:19:49:48 +0000] cupsdCheckGroup(username="anonymous", user=(nil), groupname="root")
> d [18/Oct/2012:19:49:48 +0000] get_md5_password(username="anonymous", group="root", passwd=0x7fff8fb6d3b0)
> d [18/Oct/2012:19:49:48 +0000] cupsdCheckGroup(username="anonymous", user=(nil), groupname="cups-admins")
> d [18/Oct/2012:19:49:48 +0000] get_md5_password(username="anonymous", group="cups-admins", passwd=0x7fff8fb6d3b0)
> d [18/Oct/2012:19:49:48 +0000] copy_attrs(to=0x7f0811633380, from=0x7f08113dd9b0, ra=0x7f081163dec0, group=2, quickcopy=0)
> d [18/Oct/2012:19:49:48 +0000] copy_attribute(0x7f0811633380, 0x7f08113ddcd0[time-at-creation,2,21])
> d [18/Oct/2012:19:49:48 +0000] copy_attribute(0x7f0811633380, 0x7f08113ddd10[time-at-processing,2,21])
> d [18/Oct/2012:19:49:48 +0000] copy_attribute(0x7f0811633380, 0x7f08113ddd50[time-at-completed,2,21])
> d [18/Oct/2012:19:49:48 +0000] copy_attribute(0x7f0811633380, 0x7f08113ddd90[job-id,2,21])
> d [18/Oct/2012:19:49:48 +0000] copy_attribute(0x7f0811633380, 0x7f08113dddd0[job-state,2,23])
> d [18/Oct/2012:19:49:48 +0000] copy_attribute(0x7f0811633380, 0x7f08113dde10[job-media-sheets-completed,2,21])
> d [18/Oct/2012:19:49:48 +0000] copy_attribute(0x7f0811633380, 0x7f08113dde90[job-k-octets,2,21])
> d [18/Oct/2012:19:49:48 +0000] copy_attribute(0x7f0811633380, 0x7f08113ddfd0[job-printer-state-message,2,41])
> d [18/Oct/2012:19:49:48 +0000] get_jobs: job->id=167216, dest="james-color", username="joesmith", state_value=9, attrs=(nil)
> D [18/Oct/2012:19:49:48 +0000] [Job 167216] Loading attributes...
> I [18/Oct/2012:19:49:48 +0000] Remote access is enabled.
> I [18/Oct/2012:19:49:48 +0000] Loaded configuration file "/etc/cups/cupsd.conf"
> I [18/Oct/2012:19:49:48 +0000] Using default TempDir of /var/spool/cups/tmp...
> 
> Highlighted line is where server suddenly dies and restarts. No indication why would it die. 
> 
> Any hints are much appreciated. 
> -Alex
> _______________________________________________
> cups mailing list
> cups at easysw.com
> http://lists.easysw.com/mailman/listinfo/cups

__________________________________________________
Michael Sweet, Senior Printing System Engineer, PWG Chair

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.cups.org/pipermail/cups/attachments/20121018/9eabcb30/attachment-0001.html>


More information about the cups mailing list