bug#39801: CUPS web admin page hangs

bug#39801: CUPS web admin page hangs

[hot12shots]

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

Hi,

The CUPS web interface in my Guix system hangs when loading the admin
page, making it cumbersome to manage CUPS printers and settings. The
cause appears to be that the web interface CGI scripts expect a config
file in the wrong location.


HOW TO REPRODUCE:

My system is running Guix commit 290b55c55a5 with the following CUPS
configuration:

        (service cups-service-type
          (cups-configuration
            (web-interface? #t)
            (log-level 'debug)
            (extensions (list cups-filters
                              foomatic-filters
                              hplip-minimal))))

I load http://localhost:631/admin in a browser (Icecat). Expected
behavior is for the page to load immediately. Actual behavior is the
page hangs for a minute or two, displaying a blank screen. Eventually
the expected Administration page loads, but is missing some controls
and displays "Unable to open cupsd.conf file: Success."


DETAILS:

Excerpt from /var/log/cups/error_log is attached. Note especially
CUPS_SERVERROOT=/etc/cups.

Output of ‘ps -ef | grep cupsd’:

        root      6374     1  0 00:29 ?        00:00:01
/gnu/store/wxg6fa0d1hlna6gg2nrn51fkq68q7fy9-cups-2.3.1/sbin/cupsd -f
-c /gnu/store/6i13apvx94y7q61rh3hsj7fhjb6brgf4-cupsd.conf -s
/gnu/store/nxzmy9s6inia31wvhrcrzcf66rb4v4pp-cups-files.conf

Output of ‘sudo strace -p `pidof cupsd` -f -e file’ while refreshing
the Administration page contains a number of entries like this:

        [pid  8423] access("/etc/cups/cupsd.conf", R_OK) = -1 ENOENT
(No such file or directory)

The directory /etc/cups exists but contains only ssl/ and ppd/
subdirectories, no cupsd.conf.

If I create a symlink /etc/cups/conf.d ->
/gnu/store/6i13...-cupsd.conf, the Administration page now loads
without any issue.

In addition, I noticed that (per Guix manual) the server-root field of
the CUPS service’s files-configuration section defaults to /etc/cups.
If I set that field to /gnu/store/wxg6...-cups-2.3.1/etc/cups (see the
cupsd command line above) then run ‘guix system reconfigure’ and
restart cupsd, the web interface again works as expected.

Finally, note that the ServerRoot field of
/gnu/store/nxzm...-cups-files.conf is set to
/gnu/store/wxg6...-2.3.1/etc/cups (again see cupsd command line
above).


COMMENTARY:

From examining the CUPS sources, it appears the web admin interface
expects to find cupsd.conf in CUPS_SERVERROOT solely to make the "Edit
Configuration File" feature work. This feature doesn't seem very
useful on Guix since the config file lives in the (read-only) store.
However, the file still needs to be present in order to satisfy the
admin page CGI script and keep it from hanging.

Thus, perhaps the problem could be solved by having the service make a
symlink /etc/cups/cupsd.conf pointing at its generated cupsd.conf
file.


Thanks,

Jacob

[-- Attachment #2: log --]
[-- Type: application/octet-stream, Size: 4563 bytes --]

D [26/Feb/2020:02:59:37 -0500] [Client 219] Server address is "/var/run/cups/cups.sock".
D [26/Feb/2020:02:59:37 -0500] [Client 219] Accepted from localhost (Domain)
D [26/Feb/2020:02:59:37 -0500] [Client 219] Waiting for request.
D [26/Feb/2020:02:59:37 -0500] [Client 218] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [26/Feb/2020:02:59:37 -0500] [Client 218] Closing connection.
D [26/Feb/2020:02:59:37 -0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [26/Feb/2020:02:59:37 -0500] [Client 219] GET /admin/conf/cupsd.conf HTTP/1.1
D [26/Feb/2020:02:59:37 -0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [26/Feb/2020:02:59:37 -0500] [Client 219] Read: status=200, state=3
D [26/Feb/2020:02:59:37 -0500] [Client 219] Authorized as jfirst using Local.
D [26/Feb/2020:02:59:37 -0500] cupsdIsAuthorized: username="jfirst"
D [26/Feb/2020:02:59:37 -0500] [Client 219] Processing GET /admin/conf/cupsd.conf
D [26/Feb/2020:02:59:37 -0500] [CGI] argv[0] = "/gnu/store/rjswji5nybi4wqkv8pilbbcwzszaffq8-cups-server-bin/lib/cups/cgi-bin/admin.cgi"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[0] = "variable=value"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[1] = "CUPS_CACHEDIR=/var/cache/cups"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[2] = "CUPS_DATADIR=/gnu/store/rjswji5nybi4wqkv8pilbbcwzszaffq8-cups-server-bin/share/cups"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[3] = "CUPS_DOCROOT=/gnu/store/wxg6fa0d1hlna6gg2nrn51fkq68q7fy9-cups-2.3.1/share/doc/cups"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[4] = "CUPS_FONTPATH=/gnu/store/wxg6fa0d1hlna6gg2nrn51fkq68q7fy9-cups-2.3.1/share/cups/fonts"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[5] = "CUPS_REQUESTROOT=/var/spool/cups"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[6] = "CUPS_SERVERBIN=/gnu/store/rjswji5nybi4wqkv8pilbbcwzszaffq8-cups-server-bin/lib/cups"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[7] = "CUPS_SERVERROOT=/etc/cups"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[8] = "CUPS_STATEDIR=/var/run/cups"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[9] = "HOME=/var/spool/cups/tmp"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[10] = "PATH=/gnu/store/rjswji5nybi4wqkv8pilbbcwzszaffq8-cups-server-bin/lib/cups/filter:/gnu/store/wxg6fa0d1hlna6gg2nrn51fkq68q7fy9-cups-2.3.1/b>
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[11] = "SERVER_ADMIN=root@localhost.localdomain"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[12] = "SOFTWARE=CUPS/2.3.1"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[13] = "TMPDIR=/var/spool/cups/tmp"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[14] = "USER=root"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[15] = "CUPS_MAX_MESSAGE=2047"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[16] = "CUPS_SERVER=/var/run/cups/cups.sock"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[17] = "CUPS_ENCRYPTION=IfRequested"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[18] = "IPP_PORT=631"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[19] = "AUTH_TYPE=Local"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[20] = "LANG=en.UTF8"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[21] = "REDIRECT_STATUS=1"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[22] = "GATEWAY_INTERFACE=CGI/1.1"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[23] = "SERVER_NAME=localhost"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[24] = "SERVER_PORT=631"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[25] = "REMOTE_ADDR=localhost"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[26] = "REMOTE_HOST=localhost"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[27] = "SCRIPT_NAME=/admin/conf/cupsd.conf"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[28] = "SCRIPT_FILENAME=/gnu/store/wxg6fa0d1hlna6gg2nrn51fkq68q7fy9-cups-2.3.1/share/doc/cups/admin/conf/cupsd.conf"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[29] = "REMOTE_USER=jfirst"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[30] = "SERVER_PROTOCOL=HTTP/1.1"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[31] = "HTTP_USER_AGENT=CUPS/2.3.1 (Linux 5.4.21; x86_64) IPP/2.0"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[32] = "REQUEST_METHOD=GET"
D [26/Feb/2020:02:59:37 -0500] [CGI] envp[33] = "QUERY_STRING="
D [26/Feb/2020:02:59:37 -0500] cupsdAddCert: Adding certificate for PID 12165
D [26/Feb/2020:02:59:37 -0500] [CGI] Started /gnu/store/rjswji5nybi4wqkv8pilbbcwzszaffq8-cups-server-bin/lib/cups/cgi-bin/admin.cgi (PID 12165)
I [26/Feb/2020:02:59:37 -0500] [Client 219] Started "/gnu/store/rjswji5nybi4wqkv8pilbbcwzszaffq8-cups-server-bin/lib/cups/cgi-bin/admin.cgi" (pid=12165, file=120)
D [26/Feb/2020:02:59:37 -0500] [Client 219] Waiting for CGI data.
D [26/Feb/2020:02:59:37 -0500] [CGI] admin.cgi started...