Bug#852436: cups-browsed uses 100% CPU - SOLVED (patch attached)
On 09/08/17 10:02, Cédric Dufour - Idiap Research Institute wrote:
> I confirm this issue is still present is current Debian Stable/Stretch and renders CUPS unusable in network printing environments.
> I could backport the packages from testing or experimental, but then I would miss the updates from the Debian Security team (and looking at the updates history of CUPS filters/browsed in Debian OldStable/Jessie, it is not something I'm looking forwards to)
I tracked down the issue to a timeout when 'cups-browsed' interacts with the local 'cups' server ("cupsDoFileRequest" call).
The 'cups-browsed' hard-coded timeout for such operations is 3 seconds.
This timeout is the cause of the witnessed "Unable to create/modify CUPS queue (Success)!" error messages (and 'cups-browsed' looping infinitely in attempts to add the failing printers/queues)
For large (fancy ?) PPDs, the local 'cups' server can take up to 8 (!) seconds to process the addition of a remote printer queue based on the PPD retrieved from the (BrowsePoll-ed) server (as witnessed on a 3.4GHz Intel I7-2600K test host, during wich one CPU core is stuck at 100%).
The attached patch file - for cups-filters 1.11.6 (Debian/Stretch) - allows one to configure the timeouts of both local and remote 'cups-browsed' HTTP connections, thanks to the new "HttpLocalTimeout" and "HttpRemoteTimeout" configuration settings. Setting the former to 10 seconds fixed the issue with my troublesome PPDs/printers (INEO+ copiers).
Please note that this issue will still be present in 'cups-browsed' 1.16.0 along 'cups' 2.2.4, as backported from Testing and *verified* on Stretch.
(it should not be difficult to forward-port the attached patch, however)
I hope this patch can meet your approval for its addition in Debian patches series and considered even for current Stable release (knowing that enterprise environments with big printing beasts will be bound to stumble on the same problem).
And do you have a privileged contact to propose this patch be included upstream ?
Best,
Cédric
diff -urN cups-filters-1.11.6.orig/utils/cups-browsed.c cups-filters-1.11.6/utils/cups-browsed.c
--- cups-filters-1.11.6.orig/utils/cups-browsed.c 2017-08-09 16:48:36.000000000 +0200
+++ cups-filters-1.11.6/utils/cups-browsed.c 2017-08-09 17:01:05.609442696 +0200
@@ -339,6 +339,8 @@
static guint update_netifs_sourceid = 0;
static char local_server_str[1024];
static char *DomainSocket = NULL;
+static unsigned int HttpLocalTimeout = 5;
+static unsigned int HttpRemoteTimeout = 10;
static ip_based_uris_t IPBasedDeviceURIs = IP_BASED_URIS_NO;
static unsigned int CreateRemoteRawPrinterQueues = 0;
static unsigned int CreateIPPPrinterQueues = 0;
@@ -579,6 +581,7 @@
int
http_timeout_cb(http_t *http, void *user_data)
{
+ debug_printf("HTTP timeout! (consider increasing HttpLocalTimeout/HttpRemoteTimeout value)\n");
return 0;
}
@@ -591,7 +594,7 @@
cupsEncryption());
}
if (local_conn)
- httpSetTimeout(local_conn, 3, http_timeout_cb, NULL);
+ httpSetTimeout(local_conn, HttpLocalTimeout, http_timeout_cb, NULL);
else
debug_printf("cups-browsed: Failed creating http connection to local CUPS daemon: %s:%d\n", cupsServer(), ippPort());
@@ -2617,7 +2620,7 @@
p->port);
if (http) {
/* Check whether the printer is idle, processing, or disabled */
- httpSetTimeout(http, 2, http_timeout_cb, NULL);
+ httpSetTimeout(http, HttpRemoteTimeout, http_timeout_cb, NULL);
request = ippNewRequest(CUPS_GET_PRINTERS);
ippAddStrings(request, IPP_TAG_OPERATION, IPP_TAG_KEYWORD,
"requested-attributes",
@@ -3576,7 +3579,7 @@
p->timeout = current_time + TIMEOUT_RETRY;
break;
}
- httpSetTimeout(http, 3, http_timeout_cb, NULL);
+ httpSetTimeout(http, HttpLocalTimeout, http_timeout_cb, NULL);
/* Do not auto-save option settings due to the print queue creation
process */
@@ -3629,7 +3632,7 @@
p->no_autosave = 0;
break;
}
- httpSetTimeout(remote_http, 3, http_timeout_cb, NULL);
+ httpSetTimeout(remote_http, HttpRemoteTimeout, http_timeout_cb, NULL);
if ((loadedppd = cupsGetPPD2(remote_http, p->name)) == NULL &&
CreateRemoteRawPrinterQueues == 0) {
debug_printf("Unable to load PPD file for %s from the server %s:%d!\n",
@@ -5631,7 +5634,7 @@
return;
}
- httpSetTimeout(conn, 3, http_timeout_cb, NULL);
+ httpSetTimeout(conn, HttpRemoteTimeout, http_timeout_cb, NULL);
debug_printf ("cups-browsed [BrowsePoll %s:%d]: IPP-Cancel-Subscription\n",
context->server, context->port);
@@ -5772,7 +5775,7 @@
goto fail;
}
- httpSetTimeout(conn, 3, http_timeout_cb, NULL);
+ httpSetTimeout(conn, HttpRemoteTimeout, http_timeout_cb, NULL);
if (context->can_subscribe) {
if (context->subscription_id == -1) {
@@ -6288,6 +6291,19 @@
} else if (!strcasecmp(line, "DomainSocket") && value) {
if (value[0] != '\0')
DomainSocket = strdup(value);
+ } else if ((!strcasecmp(line, "HttpLocalTimeout") || !strcasecmp(line, "HttpRemoteTimeout")) && value) {
+ int t = atoi(value);
+ if (t >= 0) {
+ if (!strcasecmp(line, "HttpLocalTimeout"))
+ HttpLocalTimeout = t;
+ else if (!strcasecmp(line, "HttpRemoteTimeout"))
+ HttpRemoteTimeout = t;
+
+ debug_printf("Set %s to %d sec.\n",
+ line, t);
+ } else
+ debug_printf("Invalid %s value: %d\n",
+ line, t);
} else if (!strcasecmp(line, "IPBasedDeviceURIs") && value) {
if (!strcasecmp(value, "IPv4") || !strcasecmp(value, "IPv4Only"))
IPBasedDeviceURIs = IP_BASED_URIS_IPV4_ONLY;
diff -urN cups-filters-1.11.6.orig/utils/cups-browsed.conf.in cups-filters-1.11.6/utils/cups-browsed.conf.in
--- cups-filters-1.11.6.orig/utils/cups-browsed.conf.in 2016-10-28 01:04:26.000000000 +0200
+++ cups-filters-1.11.6/utils/cups-browsed.conf.in 2017-08-09 17:02:50.605423497 +0200
@@ -300,6 +300,9 @@
# DomainSocket None
# DomainSocket Off
+# Set HTTP timeout [seconds] for requests sent to local/remote resources
+# HttpLocalTimeout 5
+# HttpRemoteTimeout 10
# Set IPBasedDeviceURIs to "Yes" if cups-browsed should create its
# local queues with device URIs with the IP addresses instead of the
Reply to: