[cups] Error 1282 when server has more than 200 printers and domain socket is enabled

[Alex Korobkin]

Michael,

I've added more troubleshooting info to
https://github.com/apple/cups/issues/4586
I think the problem is somewhere between GnuTLS and CUPS. If an encrypted
connection gets suddenly closed, something bad happens to cupsd process, it
gets stuck waiting for response from the broken connection.

Could you please have a look at what I've added there?

On Tue, Feb 10, 2015 at 7:28 AM, Michael Sweet <msweet at apple.com> wrote:

> Alex,
>
> > On Feb 10, 2015, at 6:58 AM, Alex Korobkin <korobkin+cups at gmail.com>
> wrote:
> >
> > Yes, it queries it in parallel to speed up processing (with the number of
> > printers being between 200 and 800 it is important).
>
> There are a number of ways to achieve a speedup without causing a
> denial-of-service, including caching the PPDs (highly recommended) and
> dispatching N threads to process batches of printers, where N < number of
> printers, and probably a smallish number (16?) on regular hardware.
>
> Regardless, you'll need to retry on failed connects and gets, with a
> back-off (sleep) of some sort.  Computers and servers do not have infinite
> resources.
>
> > Is there any hardcoded limit that I can try to increase?
>
> The kernel limits may or may not be configurable - depends on your OS and
> which limit is being tripped.  The listen backlog is normally hardcoded to
> a low number, and the total number of file descriptors somewhat higher
> (although the default per-process limit is normally 256 - cupsd increases
> its limit but maybe your application doesn't?)
>
> > Also, cupsd.conf has MaxClientsPerHost 1000, does it apply to local
> client
> > as well?
>
> Yes, absolutely.  But unless you are seeing a "max clients exceeded" error
> (I don't see that in your log snippet) I'd guess you are hitting a kernel
> limit.
>
>
> >
> > 2015-02-10 6:44 GMT-05:00 Michael Sweet <msweet at apple.com>:
> >
> >> Alex,
> >>
> >> Is the application querying the PPDs in parallel?  1282 == 0x502 ==
> >> server-error-service-unavailable, which generally means the connect()
> >> failed, either because you have exceeded the listen backlog or because
> >> cupsd is throttling you.  It sounds like the former to me (listen
> backlog
> >> exceeded...)
> >>
> >>
> >>> On Feb 9, 2015, at 4:13 PM, Alex Korobkin <korobkin+cups at gmail.com>
> >> wrote:
> >>>
> >>> On a server with CUPS 1.7.5 (and patch for STR#4484) there is an local
> >> app
> >>> that queries a list of printers, and then reads their PPDs using CUPS
> >> API.
> >>>
> >>> If I add more than 200 printers to it, local app will frequently fail
> to
> >>> retrieve a printer PPD or even get a list of printers, getting "1282
> >> Transport
> >>> endpoint is not connected" from CUPS. The more printers I add, the more
> >>> often I will see error 1282. CUPS at the same time is working fine and
> is
> >>> able to return the list of printers normally (as tested with lpstat -a
> >> and
> >>> Web UI).
> >>>
> >>> If I disable domain socket (Listen /var/run/cups/cups.sock) and restart
> >>> CUPS, the error will be gone. The app would query CUPS just fine all
> the
> >>> time, regardless of the number of printers.
> >>>
> >>> I don't see anything helpful in debug log, unfortunately.
> >>>
> >>> The only suspicious activity is frequent opening/closing of connections
> >> via
> >>> local socket:
> >>>
> >>> D [03/Feb/2015:05:42:22 +0000] [Client 52] Accepted from localhost
> >> (Domain)
> >>> D [03/Feb/2015:05:42:22 +0000] [Client 52] Waiting for request.
> >>> D [03/Feb/2015:05:42:22 +0000] [Client 52] HTTP_STATE_WAITING Closing
> on
> >> EOF
> >>> D [03/Feb/2015:05:42:22 +0000] [Client 52] Closing connection.
> >>> D [03/Feb/2015:05:42:22 +0000] [Client 52] Accepted from localhost
> >> (Domain)
> >>> D [03/Feb/2015:05:42:22 +0000] [Client 52] Waiting for request.
> >>> D [03/Feb/2015:05:42:22 +0000] [Client 52] HTTP_STATE_WAITING Closing
> on
> >> EOF
> >>> D [03/Feb/2015:05:42:22 +0000] [Client 52] Closing connection.
> >>> D [03/Feb/2015:05:42:22 +0000] [Client 52] Accepted from localhost
> >> (Domain)
> >>> D [03/Feb/2015:05:42:22 +0000] [Client 52] Waiting for request.
> >>> D [03/Feb/2015:05:42:22 +0000] [Client 52] HTTP_STATE_WAITING Closing
> on
> >> EOF
> >>> D [03/Feb/2015:05:42:22 +0000] [Client 52] Closing connection.
> >>>
> >>> --
> >>> 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
> >>
> >
> >
> >
> > --
> > -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
>



-- 
-Alex