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

Mon Oct 22 10:27:43 PDT 2012

Here you go, "Broken pipe".
I tried to load debug symbols, but it didn't help to pin-point the actual
line of code.

(gdb) run -f
Starting program: /usr/sbin/cupsd -f
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/usr/grte/v2/lib64/libthread_db.so.1".
No limit for Validate-Job defined in policy default and no suitable
template found.
No limit for Cancel-Jobs defined in policy default - using Pause-Printer's
policy.
No limit for Cancel-My-Jobs defined in policy default - using
Send-Document's policy.
No limit for Close-Job defined in policy default - using Send-Document's
policy.
No JobPrivateAccess defined in policy default - using defaults.
No JobPrivateValues defined in policy default - using defaults.
No SubscriptionPrivateAccess defined in policy default - using defaults.
No SubscriptionPrivateValues defined in policy default - using defaults.

Program received signal SIGPIPE, Broken pipe.
0x00007f8f2a741e72 in send () from /lib/libpthread.so.0
(gdb) bt
#0  0x00007f8f2a741e72 in send () from /lib/libpthread.so.0
#1  0x00007f8f2b4165d2 in ?? () from /usr/lib/libgnutls.so.26
#2  0x00007f8f2b41379d in _gnutls_send_int () from /usr/lib/libgnutls.so.26
#3  0x00007f8f2b416193 in ?? () from /usr/lib/libgnutls.so.26
#4  0x00007f8f2b41a030 in ?? () from /usr/lib/libgnutls.so.26
#5  0x00007f8f2b41e01b in ?? () from /usr/lib/libgnutls.so.26
#6  0x00007f8f2b41bb85 in ?? () from /usr/lib/libgnutls.so.26
#7  0x00007f8f2b41bc29 in gnutls_handshake () from /usr/lib/libgnutls.so.26
#8  0x00007f8f2badad44 in ?? ()
#9  0x00007f8f2e56ef20 in ?? ()
#10 0x00007f8f2bd321f0 in ?? ()
#11 0x00007f8f2d5d32a0 in ?? ()
#12 0x00007f8f2badc05c in ?? ()
#13 0x00007f8f00000004 in ?? ()
#14 0x00007f8f2bd324f4 in ?? ()
#15 0x00007f8f2d5d32a4 in ?? ()
#16 0x00000000ffffffff in ?? ()
#17 0x00007f8f2e55d500 in ?? ()
#18 0x0000000100000010 in ?? ()
#19 0x0100007fbb010002 in ?? ()
#20 0x0000000000000000 in ?? ()

On 18 October 2012 19:03, Michael Sweet <msweet at apple.com> wrote:

> 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
>
>
> _______________________________________________
> cups mailing list
> cups at easysw.com
> http://lists.easysw.com/mailman/listinfo/cups
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.cups.org/pipermail/cups/attachments/20121022/16b2dc5e/attachment-0001.html>