Subject: bug#42068: CUPS :631/admin interface freezes

From: Tobias Geerinckx-Rice <[email-masked]>
Date: Fri, 26 Jun 2020 23:18:26 +0200

Guix,

When visiting localhost:631/admin, the server appears to freeze 
(blank page).  However, exactly 2 minutes later content is served 
and buttons like ‘Find New Printer’ [appear to] work without 
delay.

Some error_log debug output below.  Note the 2 neat 1-minute 
time-outs.

It's likely that this is an upstream bug (but not quite this [1]). 
I'll try upgrading CUPS and gathering more infos.

Kind regards,

T G-R

[1]: https://github.com/apple/cups/issues/5755

--8<---------------cut here---------------start------------->8---
D [26/Jun/2020:22:30:44 +0200] [Client 1199] Waiting for CGI data.
D [26/Jun/2020:22:30:44 +0200] [CGI] admin.cgi started...
D [26/Jun/2020:22:30:44 +0200] [CGI] http=0x572bbd388140
D [26/Jun/2020:22:30:44 +0200] [CGI] cgiSetVariable: 
SECTION=\"admin\"
D [26/Jun/2020:22:30:44 +0200] [CGI] cgiSetVariable: 
REFRESH_PAGE=\"\"
D [26/Jun/2020:22:30:44 +0200] [CGI] org.cups.sid cookie not 
found, initializing!
D [26/Jun/2020:22:30:44 +0200] [CGI] org.cups.sid cookie is 
\"7be9c6067fac85f5930e650697b46a8e\"
D [26/Jun/2020:22:30:44 +0200] [CGI] No form data, showing main 
menu...
D [26/Jun/2020:22:31:44 +0200] Report: clients=100
D [26/Jun/2020:22:31:44 +0200] Report: jobs=0
D [26/Jun/2020:22:31:44 +0200] Report: jobs-active=0
D [26/Jun/2020:22:31:44 +0200] Report: printers=1
D [26/Jun/2020:22:31:44 +0200] Report: 
stringpool-string-count=2150
D [26/Jun/2020:22:31:44 +0200] Report: 
stringpool-alloc-bytes=14480
D [26/Jun/2020:22:31:44 +0200] Report: 
stringpool-total-bytes=43296
D [26/Jun/2020:22:32:44 +0200] [Client 807] Closing on unexpected 
HTTP read state HTTP_STATE_GET_SEND.
D [26/Jun/2020:22:32:44 +0200] [Client 807] Closing connection.
D [26/Jun/2020:22:32:44 +0200] cupsdSetBusyState: newbusy="Active 
clients", busy="Active clients"
I [26/Jun/2020:22:32:44 +0200] Resuming new connection 
processing...
D [26/Jun/2020:22:32:44 +0200] Report: clients=99
D [26/Jun/2020:22:32:44 +0200] Report: jobs=0
D [26/Jun/2020:22:32:44 +0200] Report: jobs-active=0
D [26/Jun/2020:22:32:44 +0200] Report: printers=1
D [26/Jun/2020:22:32:44 +0200] Report: 
stringpool-string-count=2150
D [26/Jun/2020:22:32:44 +0200] Report: 
stringpool-alloc-bytes=14480
D [26/Jun/2020:22:32:44 +0200] Report: 
stringpool-total-bytes=43296
D [26/Jun/2020:22:32:44 +0200] cupsdSetBusyState: newbusy="Active 
clients", busy="Active clients"
D [26/Jun/2020:22:32:44 +0200] [Client 1200] Server address is 
"/var/run/cups/cups.sock".
D [26/Jun/2020:22:32:44 +0200] [Client 1200] Accepted from 
localhost (Domain)
D [26/Jun/2020:22:32:44 +0200] [Client 1200] Waiting for request.
W [26/Jun/2020:22:32:44 +0200] Max clients reached, holding new 
connections...
D [26/Jun/2020:22:32:44 +0200] [Client 1200] GET 
/admin/conf/cupsd.conf HTTP/1.1
D [26/Jun/2020:22:32:44 +0200] cupsdSetBusyState: newbusy="Active 
clients", busy="Active clients"
D [26/Jun/2020:22:32:44 +0200] [Client 1200] Read: status=200, 
state=3
D [26/Jun/2020:22:32:44 +0200] [Client 1200] No authentication 
data provided.
D [26/Jun/2020:22:32:44 +0200] cupsdIsAuthorized: username=""
D [26/Jun/2020:22:32:44 +0200] [Client 1200] cupsdSendHeader: 
code=401, type="text/html", auth_type=0
D [26/Jun/2020:22:32:44 +0200] [Client 1200] WWW-Authenticate: 
Basic realm=\"CUPS\", PeerCred, Local trc=\"y\"
D [26/Jun/2020:22:32:44 +0200] [Client 1200] Closing connection.
D [26/Jun/2020:22:32:44 +0200] cupsdSetBusyState: newbusy="Active 
clients", busy="Active clients"
I [26/Jun/2020:22:32:44 +0200] Resuming new connection 
processing...
D [26/Jun/2020:22:32:44 +0200] [Client 811] Closing on unexpected 
HTTP read state HTTP_STATE_GET_SEND.
D [26/Jun/2020:22:32:44 +0200] [Client 811] Closing connection.
D [26/Jun/2020:22:32:44 +0200] cupsdSetBusyState: newbusy="Active 
clients", busy="Active clients"
D [26/Jun/2020:22:32:44 +0200] PID 7754 
(/gnu/store/w6wnki4glaxxwmdh56fqf4yis3k7n8yg-cups-server-bin/lib/cups/cg>
D [26/Jun/2020:22:32:44 +0200] [Client 815] Closing on unexpected 
HTTP read state HTTP_STATE_GET_SEND.
D [26/Jun/2020:22:32:44 +0200] [Client 815] Closing connection.
D [26/Jun/2020:22:32:44 +0200] cupsdSetBusyState: newbusy="Active 
clients", busy="Active clients"
D [26/Jun/2020:22:32:44 +0200] PID 7755 
(/gnu/store/w6wnki4glaxxwmdh56fqf4yis3k7n8yg-cups-server-bin/lib/cups/cg>
D [26/Jun/2020:22:32:44 +0200] [Client 819] Closing on unexpected 
HTTP read state HTTP_STATE_GET_SEND.
D [26/Jun/2020:22:32:44 +0200] [Client 819] Closing connection.
D [26/Jun/2020:22:32:44 +0200] cupsdSetBusyState: newbusy="Active 
clients", busy="Active clients"
D [26/Jun/2020:22:32:44 +0200] PID 7756 
(/gnu/store/w6wnki4glaxxwmdh56fqf4yis3k7n8yg-cups-server-bin/lib/cups/cg>
D [26/Jun/2020:22:32:44 +0200] [Client 823] Closing on unexpected 
HTTP read state HTTP_STATE_GET_SEND.
D [26/Jun/2020:22:32:44 +0200] [Client 823] Closing connection.
--8<---------------cut here---------------end--------------->8---