[cups] CUPS randomly freezing when returning list of printers to the client

[Michael Sweet]

Most likely this is CUPS STR #4484.  A fix is in progress, but basically GNU TLS is doing some pre-initialization that is causing problems, which is compounded by a subtle initialization bug when cupsd is running in daemon mode.


> On Oct 31, 2014, at 12:52 PM, Alex Korobkin <korobkin+cups at gmail.com> wrote:
> 
> Yes, it is set to Required.
> On 31 Oct 2014 11:52, "Michael Sweet" <msweet at apple.com> wrote:
> 
>> Do you have encryption enabled on the server?
>> 
>>> On Oct 28, 2014, at 5:46 PM, Alex Korobkin <korobkin+cups at gmail.com>
>> wrote:
>>> 
>>> I have a weird problem with a busy CUPS 1.7.5 running on Ubuntu server
>>> 12.04 x64.
>>> 
>>> It would freeze several times per hour, last message in the log always
>>> being about cupsdWriteClient, when replying to a random Linux client
>> while
>>> returning the list of printers.
>>> 
>>> D [28/Oct/2014:20:18:28 +0000] [Client 152] Returning IPP successful-ok
>> for
>>> CUPS-Get-Printers (no URI) from 172.16.60.111
>>> D [28/Oct/2014:20:18:28 +0000] [Client 152] Content-Length: 442727
>>> D [28/Oct/2014:20:18:28 +0000] [Client 152] cupsdWriteClient error=0,
>>> used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH,
>>> data_remaining=442727, response=0x7fb93e163360(IPP_IDLE), pipe_pid=0,
>>> file=-1
>>> 
>>> strace shows the process being stuck at sendto() as well.
>>> 
>>> 20:18:29 sendto(152,
>>> 
>> "\27\3\3\10\20\361\233\275\26\243,\226\243\204\346\201\275\3\301\315\321\217\336\6\367\271hV\"\231kI:\312F\214k5\324y\311_\234\227\2049\3034\311\217\27\242a/\7\244\332C\274:\302\335\"\n"...,
>>> 2069, 0, NULL, 0) = 2069
>>> 20:18:29 getrusage(RUSAGE_SELF, {ru_utime={72, 598642}, ru_stime={19,
>>> 631219}, ...}) = 0
>>> 20:18:29 times({tms_utime=7259, tms_stime=1963, tms_cutime=750,
>>> tms_cstime=242}) = 1835914399
>>> 20:18:29 getrusage(RUSAGE_SELF, {ru_utime={72, 598642}, ru_stime={19,
>>> 631219}, ...}) = 0
>>> 20:18:29 times({tms_utime=7259, tms_stime=1963, tms_cutime=750,
>>> tms_cstime=242}) = 1835914399
>>> 20:18:29 sendto(152,
>>> "\27\3\3\10@\31F\256\3R\215[\323\212W\255a\225/\214@
>> \3433?\21HX{.\3207>k\260q\"+\0174\361\34\215\37\261+)L$\326\360\nw|1\25\36\207.<\27\365\366\305`"...,
>>> 2117, 0, NULL, 0 <unfinished ...>
>>> 
>>> No other log indicates any problems: the machine has lots of TCP sockets,
>>> high ulimit for open files, etc.
>>> 
>>> Any suggestions on what to look for?
>>> --
>>> -Alex
>>> _______________________________________________
>>> cups mailing list
>>> cups at cups.org
>>> https://www.cups.org/mailman/listinfo/cups
>> 
>> _________________________________________________________
>> Michael Sweet, Senior Printing System Engineer, PWG Chair
>> 
>> _______________________________________________
>> cups mailing list
>> cups at cups.org
>> https://www.cups.org/mailman/listinfo/cups
>> 
> _______________________________________________
> cups mailing list
> cups at cups.org
> https://www.cups.org/mailman/listinfo/cups

_________________________________________________________
Michael Sweet, Senior Printing System Engineer, PWG Chair