The machine running our CUPS print server at home recently had to be replaced by another one. Today we had to set up a new CUPS client to print to the CUPS server running on the new machine.

It turns out it was not an easy experience — the CUPS client kept saying “Bad Request” and there was nothing in the CUPS log files on the server side. We then realized that we were logging at a level that could be hiding important messages, based on this parameter in /etc/cups/cupsd.conf:

LogLevel warn

Changing this parameter to:

LogLevel debug

and trying again to print or modify the printer produced the following messages in /var/log/cups/error.log:

D [04/Dec/2016:16:30:58 -0500] [Client 1] GET /printers/HP_Officejet_2620_series.ppd HTTP/1.1
D [04/Dec/2016:16:30:58 -0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [04/Dec/2016:16:30:58 -0500] [Client 1] Read: status=200
D [04/Dec/2016:16:30:58 -0500] [Client 1] No authentication data provided.
E [04/Dec/2016:16:30:58 -0500] [Client 1] Request from "[v1.2003:1480:eca5:1120:7e7a:91ff:febf:d3b2]" using invalid Host: field "printer.example.com:631".
D [04/Dec/2016:16:30:58 -0500] [Client 1] cupsdSendHeader: code=400, type="text/html", auth_type=0
D [04/Dec/2016:16:30:58 -0500] [Client 1] Closing because Keep-Alive is disabled.
D [04/Dec/2016:16:30:58 -0500] [Client 1] Closing connection.

Aha! ‘Request from “[v1.2003:1480:eca5:1120:7e7a:91ff:febf:d3b2]” using invalid Host: field’!

Now with an actual error message to search for I was able to find Debian bug #530027, which has as a “workaround” to set “ServerAlias *” in /etc/cups/cupsd.conf.

After making that change and reloading CUPS things started to work. Note that the root cause of the problem is that the hostname of the print server changed, and the CUPS client was using the hostname of the old server via a DNS CNAME.

Beats me why such an error message is not produced unless the CUPS logging level is set to “debug”.