bug#42068: CUPS :631/admin interface freezes

bug#42068: CUPS :631/admin interface freezes

[Tobias Geerinckx-Rice via Bug reports for GNU Guix]

[-- Attachment #1: Type: text/plain, Size: 5022 bytes --]

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---

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 227 bytes --]

bug#42068: CUPS :631/admin interface freezes

[Tobias Geerinckx-Rice via Bug reports for GNU Guix]

[-- Attachment #1: Type: text/plain, Size: 728 bytes --]

I've pushed some patches I've been using since ‘forever’ to 
core-updates.  They simply remove the entire right-hand ‘Server’ 
form, and short-circuit the logic behind it that caused the long 
delays.

An older work-around I tried was to simply link to the store 
cupsd.conf in /etc/cups.  This solves the immediate problem, and 
even allows viewing (not editing) a few settings in said form. 
It's an option for those who can't wait for core-updates to be 
merged (don't forget to delete it next year… :-).

However, doing so merely hides the fact that this code is broken 
with -c FILE by effectively circumventing the option in a very 
sneaky way.  A step back, not forward.

Kind regards,

T G-R

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 247 bytes --]