Dear @misc reader, my HP Deskjet F4280 USB printer is (again!) not working after CUPS update to v2.0.1 in current.
ulpt* is of course disabled, devices' permissions seem ok and the printer is correctly recognized: Console log for poseidon.atlantide.net ugen1 at uhub8 port 4 "HP Deskjet F4200 series" rev 2.00/1.00 addr 7 just22@poseidon:[~]> ls -la /dev/ugen1.* crw-rw---- 1 _cups _saned 63, 16 Nov 28 22:22 /dev/ugen1.00 crw-rw---- 1 _cups _saned 63, 17 Nov 28 22:22 /dev/ugen1.01 crw-rw---- 1 _cups _saned 63, 18 Nov 28 22:22 /dev/ugen1.02 crw-rw---- 1 _cups _saned 63, 19 Nov 28 22:22 /dev/ugen1.03 crw-rw---- 1 _cups _saned 63, 20 Nov 28 22:22 /dev/ugen1.04 crw-rw---- 1 _cups _saned 63, 21 Nov 28 22:22 /dev/ugen1.05 crw-rw---- 1 _cups _saned 63, 22 Nov 28 22:22 /dev/ugen1.06 crw-rw---- 1 _cups _saned 63, 23 Nov 28 22:22 /dev/ugen1.07 crw-rw---- 1 _cups _saned 63, 24 Nov 28 22:22 /dev/ugen1.08 crw-rw---- 1 _cups _saned 63, 25 Nov 28 22:22 /dev/ugen1.09 crw-rw---- 1 _cups _saned 63, 26 Nov 28 22:22 /dev/ugen1.10 crw-rw---- 1 _cups _saned 63, 27 Nov 28 22:22 /dev/ugen1.11 crw-rw---- 1 _cups _saned 63, 28 Nov 28 22:22 /dev/ugen1.12 crw-rw---- 1 _cups _saned 63, 29 Nov 28 22:22 /dev/ugen1.13 crw-rw---- 1 _cups _saned 63, 30 Nov 28 22:22 /dev/ugen1.14 crw-rw---- 1 _cups _saned 63, 31 Nov 28 22:22 /dev/ugen1.15 just22@poseidon:[~]> ls -la /dev/usb* crw-rw---- 1 root wheel 61, 0 Nov 28 22:22 /dev/usb0 crw-rw---- 1 _cups _saned 61, 1 Nov 28 22:22 /dev/usb1 crw-rw---- 1 root wheel 61, 2 Nov 28 22:22 /dev/usb2 crw-rw---- 1 root wheel 61, 3 Nov 28 22:22 /dev/usb3 crw-rw---- 1 root wheel 61, 4 Nov 28 22:22 /dev/usb4 crw-rw---- 1 root wheel 61, 5 Nov 28 22:22 /dev/usb5 crw-rw---- 1 root wheel 61, 6 Nov 28 22:22 /dev/usb6 crw-rw---- 1 root wheel 61, 7 Nov 28 22:22 /dev/usb7 just22@poseidon:[~]> lsusb Bus 000 Device 001: ID 8086:0000 Intel Corp. Bus 001 Device 001: ID 8086:0000 Intel Corp. Bus 001 Device 002: ID 05e3:0608 Genesys Logic, Inc. USB-2.0 4-Port HUB Bus 001 Device 003: ID 05e3:0608 Genesys Logic, Inc. USB-2.0 4-Port HUB Bus 001 Device 004: ID 03f0:0024 Hewlett-Packard KU-0316 Keyboard Bus 001 Device 005: ID 046d:c050 Logitech, Inc. RX 250 Optical Mouse Bus 001 Device 006: ID 046d:089d Logitech, Inc. QuickCam E2500 series Bus 001 Device 007: ID 03f0:2504 Hewlett-Packard DeskJet F4200 series Bus 002 Device 001: ID 8086:0000 Intel Corp. Bus 003 Device 001: ID 8086:0000 Intel Corp. Bus 004 Device 001: ID 8086:0000 Intel Corp. Bus 004 Device 002: ID 046d:c52b Logitech, Inc. Unifying Receiver Bus 005 Device 001: ID 8086:0000 Intel Corp. Bus 006 Device 001: ID 8086:0000 Intel Corp. just22@poseidon:[~]> sudo /usr/local/libexec/cups/backend/usb DEBUG: Loading USB quirks from "/usr/local/share/cups/usb". DEBUG: Loaded 71 quirks. DEBUG: list_devices DEBUG: libusb_get_device_list=14 DEBUG2: Printer found with device ID: MFG:HP;MDL:Deskjet F4200 series;CMD:MLC,PCL,PML,DW-PCL,DESKJET,DYN;1284.4DL:4d,4e,1;CLS:PRINTER;DES:CB656B;SN:CN8C54F12J05BR;S:038000C486001021002c1f0002ac0000000;J: ;Z:0102,0503b608000000,0600,0c0,0e00000000,0f00000000,10000002000002,12000,147,150; Device URI: usb://HP/Deskjet%20F4200%20series?serial=CN8C54F12J05BR&interface=1 direct usb://HP/Deskjet%20F4200%20series?serial=CN8C54F12J05BR&interface=1 "HP Deskjet F4200 series" "HP Deskjet F4200 series" "MFG:HP;MDL:Deskjet F4200 series;CMD:MLC,PCL,PML,DW-PCL,DESKJET,DYN;1284.4DL:4d,4e,1;CLS:PRINTER;DES:CB656B;SN:CN8C54F12J05BR;S:038000C486001021002c1f0002ac0000000;J: ;Z:0102,0503b608000000,0600,0c0,0e00000000,0f00000000,10000002000002,12000,147,150;" "" Since I was not able to print, I tried to delete and reinstall the printer from the CUPS web interface (and from HPLIP GUI too), but, even if the operation seems to complete flawlessly and the /etc/cups/printer.conf is written correctly, the printer isn't listed among the available devices in CUPS. After enabling "Save debugging information for troubleshooting" in CUPS, this is the relevant content of /var/log/cups/error_log D [03/Dec/2014:08:57:49 +0100] CUPS-Add-Modify-Printer ipp://localhost/printers/HP_Deskjet_F4280 D [03/Dec/2014:08:57:49 +0100] cupsdIsAuthorized: username="" D [03/Dec/2014:08:57:49 +0100] [Client 84] Returning HTTP Unauthorized for CUPS-Add-Modify-Printer (ipp://localhost/printers/HP_Deskjet_F4280) from localhost D [03/Dec/2014:08:57:49 +0100] [Client 84] cupsdSendHeader: code=401, type="text/html", auth_type=1 D [03/Dec/2014:08:57:49 +0100] [Client 84] WWW-Authenticate: Basic realm="CUPS", trc="y" D [03/Dec/2014:08:57:49 +0100] [Client 85] Accepted from localhost (Domain) D [03/Dec/2014:08:57:49 +0100] [Client 85] Waiting for request. D [03/Dec/2014:08:57:49 +0100] [Client 86] Accepted from localhost (Domain) D [03/Dec/2014:08:57:49 +0100] [Client 86] Waiting for request. D [03/Dec/2014:08:57:49 +0100] [Client 85] HTTP_STATE_WAITING Closing for error 32 (Broken pipe) D [03/Dec/2014:08:57:49 +0100] [Client 85] Closing connection. D [03/Dec/2014:08:57:49 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files" D [03/Dec/2014:08:57:49 +0100] [Client 87] Accepted from localhost (Domain) D [03/Dec/2014:08:57:49 +0100] [Client 87] Waiting for request. D [03/Dec/2014:08:57:49 +0100] [Client 86] HTTP_STATE_WAITING Closing for error 32 (Broken pipe) D [03/Dec/2014:08:57:49 +0100] [Client 86] Closing connection. D [03/Dec/2014:08:57:49 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files" D [03/Dec/2014:08:57:49 +0100] [Client 87] POST /admin/ HTTP/1.1 D [03/Dec/2014:08:57:49 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files" D [03/Dec/2014:08:57:49 +0100] [Client 87] Read: status=200 D [03/Dec/2014:08:57:49 +0100] [Client 87] Authorized as root using Local D [03/Dec/2014:08:57:49 +0100] [Client 87] 2.0 CUPS-Add-Modify-Printer 1 D [03/Dec/2014:08:57:49 +0100] [Client 87] Read: status=100 D [03/Dec/2014:08:57:49 +0100] [Client 87] Read: status=100 D [03/Dec/2014:08:57:49 +0100] [Client 87] Read: status=100 D [03/Dec/2014:08:57:49 +0100] [Client 87] Read: status=100 D [03/Dec/2014:08:57:49 +0100] [Client 87] Read: status=100 D [03/Dec/2014:08:57:49 +0100] [Client 87] Read: status=100 D [03/Dec/2014:08:57:49 +0100] [Client 87] Read: status=100 D [03/Dec/2014:08:57:49 +0100] CUPS-Add-Modify-Printer ipp://localhost/printers/HP_Deskjet_F4280 D [03/Dec/2014:08:57:49 +0100] cupsdIsAuthorized: username="root" D [03/Dec/2014:08:57:49 +0100] Setting printer-error-policy to "stop-printer"... D [03/Dec/2014:08:57:49 +0100] Setting printer-op-policy to "default"... D [03/Dec/2014:08:57:49 +0100] Copied PPD file successfully D [03/Dec/2014:08:57:49 +0100] cupsdMarkDirty(P----) D [03/Dec/2014:08:57:49 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files" D [03/Dec/2014:08:57:49 +0100] Calling FindDeviceById(cups-HP_Deskjet_F4280) D [03/Dec/2014:08:57:49 +0100] FindDeviceById failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files D [03/Dec/2014:08:57:49 +0100] Using profile ID "HP_Deskjet_F4280-Gray..". D [03/Dec/2014:08:57:49 +0100] Calling CreateProfile(HP_Deskjet_F4280-Gray..,temp) W [03/Dec/2014:08:57:49 +0100] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files D [03/Dec/2014:08:57:49 +0100] Using profile ID "HP_Deskjet_F4280-RGB..". D [03/Dec/2014:08:57:49 +0100] Calling CreateProfile(HP_Deskjet_F4280-RGB..,temp) W [03/Dec/2014:08:57:49 +0100] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files I [03/Dec/2014:08:57:49 +0100] Registering ICC color profiles for "HP_Deskjet_F4280". D [03/Dec/2014:08:57:49 +0100] Calling CreateDevice(cups-HP_Deskjet_F4280,temp) W [03/Dec/2014:08:57:49 +0100] CreateDevice failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files D [03/Dec/2014:08:57:49 +0100] cupsdMarkDirty(P----) D [03/Dec/2014:08:57:49 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files" D [03/Dec/2014:08:57:49 +0100] load_ppd: Loading /etc/cups/ppd/HP_Deskjet_F4280.ppd... D [03/Dec/2014:08:57:49 +0100] load_ppd: Saving /var/cache/cups/HP_Deskjet_F4280.data... D [03/Dec/2014:08:57:49 +0100] cupsdRegisterPrinter(p=0xa3b4ed24000(HP_Deskjet_F4280)) D [03/Dec/2014:08:57:49 +0100] cupsdMarkDirty(P----) D [03/Dec/2014:08:57:49 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files" D [03/Dec/2014:08:57:49 +0100] cupsdMarkDirty(--p--) D [03/Dec/2014:08:57:49 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files" D [03/Dec/2014:08:57:49 +0100] Discarding unused printer-modified event... I [03/Dec/2014:08:57:49 +0100] Printer "HP_Deskjet_F4280" modified by "root". D [03/Dec/2014:08:57:49 +0100] [Client 87] Returning IPP successful-ok for CUPS-Add-Modify-Printer (ipp://localhost/printers/HP_Deskjet_F4280) from localhost D [03/Dec/2014:08:57:49 +0100] [Client 87] Content-Length: 75 D [03/Dec/2014:08:57:49 +0100] [Client 87] cupsdSendHeader: code=200, type="application/ipp", auth_type=0 D [03/Dec/2014:08:57:49 +0100] [Client 87] con->http=0xa3c33c42000 D [03/Dec/2014:08:57:49 +0100] [Client 87] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=75, response=0xa3c15063500(IPP_STATE_DATA), pipe_pid=0, file=-1 D [03/Dec/2014:08:57:49 +0100] [Client 87] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0 D [03/Dec/2014:08:57:49 +0100] [Client 87] bytes=0, http_state=0, data_remaining=75 D [03/Dec/2014:08:57:49 +0100] [Client 87] Flushing write buffer. D [03/Dec/2014:08:57:49 +0100] [Client 87] New state is HTTP_STATE_WAITING D [03/Dec/2014:08:57:49 +0100] [Client 87] Waiting for request. D [03/Dec/2014:08:57:49 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files" D [03/Dec/2014:08:57:49 +0100] [CGI] cgiSetVariable: refresh_page="5;URL=/admin/?OP=redirect&URL=/printers/HP_Deskjet_F4280" D [03/Dec/2014:08:57:49 +0100] [CGI] cgiSetVariable: TITLE="Set Printer Options" D [03/Dec/2014:08:57:49 +0100] [CGI] cgiSetVariable: SERVER_NAME="localhost" D [03/Dec/2014:08:57:49 +0100] [CGI] cgiSetVariable: REMOTE_USER="root" D [03/Dec/2014:08:57:49 +0100] [CGI] cgiSetVariable: CUPS_VERSION="CUPS v2.0.1" D [03/Dec/2014:08:57:49 +0100] [Client 77] CGI data ready to be sent. D [03/Dec/2014:08:57:49 +0100] [Client 77] con->http=0xa3bfc0cb000 D [03/Dec/2014:08:57:49 +0100] [Client 77] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=0x0(), pipe_pid=25407, file=21 D [03/Dec/2014:08:57:49 +0100] [Client 77] Waiting for CGI data. D [03/Dec/2014:08:57:49 +0100] [Client 77] Script header: Content-Type: text/html;charset=utf-8 D [03/Dec/2014:08:57:49 +0100] [Client 77] Script header: D [03/Dec/2014:08:57:49 +0100] [Client 77] Sending status 200 for CGI. D [03/Dec/2014:08:57:49 +0100] [Client 77] cupsdSendHeader: code=200, type="(null)", auth_type=0 D [03/Dec/2014:08:57:49 +0100] [Client 77] con->http=0xa3bfc0cb000 D [03/Dec/2014:08:57:49 +0100] [Client 77] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0x0(), pipe_pid=25407, file=21 D [03/Dec/2014:08:57:49 +0100] [Client 77] Waiting for CGI data. D [03/Dec/2014:08:57:49 +0100] [Client 77] CGI data ready to be sent. D [03/Dec/2014:08:57:49 +0100] [Client 77] con->http=0xa3bfc0cb000 D [03/Dec/2014:08:57:49 +0100] [Client 77] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0x0(), pipe_pid=25407, file=21 D [03/Dec/2014:08:57:49 +0100] [Client 77] Waiting for CGI data. D [03/Dec/2014:08:57:49 +0100] [Client 77] con->http=0xa3bfc0cb000 D [03/Dec/2014:08:57:49 +0100] [Client 77] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0x0(), pipe_pid=25407, file=21 D [03/Dec/2014:08:57:49 +0100] [Client 77] Waiting for CGI data. D [03/Dec/2014:08:57:49 +0100] [Client 77] CGI data ready to be sent. D [03/Dec/2014:08:57:49 +0100] [Client 77] con->http=0xa3bfc0cb000 D [03/Dec/2014:08:57:49 +0100] [Client 77] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0x0(), pipe_pid=25407, file=21 D [03/Dec/2014:08:57:49 +0100] [Client 77] Waiting for CGI data. D [03/Dec/2014:08:57:49 +0100] [Client 77] con->http=0xa3bfc0cb000 D [03/Dec/2014:08:57:49 +0100] [Client 77] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0x0(), pipe_pid=25407, file=21 D [03/Dec/2014:08:57:49 +0100] [Client 77] Waiting for CGI data. D [03/Dec/2014:08:57:49 +0100] [Client 77] CGI data ready to be sent. D [03/Dec/2014:08:57:49 +0100] [Client 77] con->http=0xa3bfc0cb000 D [03/Dec/2014:08:57:49 +0100] [Client 77] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0x0(), pipe_pid=25407, file=21 D [03/Dec/2014:08:57:49 +0100] [Client 77] Waiting for CGI data. D [03/Dec/2014:08:57:49 +0100] [Client 77] con->http=0xa3bfc0cb000 D [03/Dec/2014:08:57:49 +0100] [Client 77] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0x0(), pipe_pid=25407, file=21 D [03/Dec/2014:08:57:49 +0100] [Client 77] Waiting for CGI data. D [03/Dec/2014:08:57:49 +0100] [Client 87] HTTP_STATE_WAITING Closing for error 32 (Broken pipe) D [03/Dec/2014:08:57:49 +0100] [Client 87] Closing connection. D [03/Dec/2014:08:57:49 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files" D [03/Dec/2014:08:57:49 +0100] PID 25407 (/usr/local/libexec/cups/cgi-bin/admin.cgi) exited with no errors. D [03/Dec/2014:08:57:49 +0100] [Client 77] CGI data ready to be sent. D [03/Dec/2014:08:57:49 +0100] [Client 77] con->http=0xa3bfc0cb000 D [03/Dec/2014:08:57:49 +0100] [Client 77] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0x0(), pipe_pid=25407, file=21 D [03/Dec/2014:08:57:49 +0100] [Client 77] Waiting for CGI data. D [03/Dec/2014:08:57:49 +0100] [Client 77] Sending 0-length chunk. D [03/Dec/2014:08:57:49 +0100] [Client 77] Flushing write buffer. D [03/Dec/2014:08:57:49 +0100] [Client 77] New state is HTTP_STATE_WAITING D [03/Dec/2014:08:57:49 +0100] [Client 77] Waiting for request. D [03/Dec/2014:08:57:49 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files" D [03/Dec/2014:08:57:54 +0100] [Client 77] GET /admin/?OP=redirect&URL=/printers/HP_Deskjet_F4280 HTTP/1.1 D [03/Dec/2014:08:57:54 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files" D [03/Dec/2014:08:57:54 +0100] [Client 77] Read: status=200 D [03/Dec/2014:08:57:54 +0100] [Client 77] Authorized as root using Basic D [03/Dec/2014:08:57:54 +0100] [Client 77] Processing GET /admin/?OP=redirect&URL=/printers/HP_Deskjet_F4280 D [03/Dec/2014:08:57:54 +0100] [CGI] argv[0] = "/usr/local/libexec/cups/cgi-bin/admin.cgi" D [03/Dec/2014:08:57:54 +0100] [CGI] argv[1] = "OP=redirect&URL=/printers/HP_Deskjet_F4280" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[0] = "CUPS_CACHEDIR=/var/cache/cups" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[1] = "CUPS_DATADIR=/usr/local/share/cups" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[2] = "CUPS_DOCROOT=/usr/local/share/doc/cups" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[3] = "CUPS_FONTPATH=/usr/local/share/cups/fonts" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[4] = "CUPS_REQUESTROOT=/var/spool/cups" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/local/libexec/cups" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[6] = "CUPS_SERVERROOT=/etc/cups" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[7] = "CUPS_STATEDIR=/var/run/cups" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[8] = "HOME=/var/spool/cups/tmp" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[9] = "PATH=/usr/local/libexec/cups/filter:/usr/local/bin:/usr/local/sbin:/bin:/usr/bin" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[10] = "SERVER_ADMIN=r...@poseidon.atlantide.net" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[11] = "SOFTWARE=CUPS/2.0.1" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[12] = "TMPDIR=/var/spool/cups/tmp" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[13] = "USER=root" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[14] = "CUPS_MAX_MESSAGE=2047" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[15] = "CUPS_SERVER=/var/run/cups/cups.sock" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[16] = "CUPS_ENCRYPTION=IfRequested" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[17] = "IPP_PORT=631" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[18] = "AUTH_TYPE=Basic" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[19] = "LANG=en_US.UTF8" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[20] = "REDIRECT_STATUS=1" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[21] = "GATEWAY_INTERFACE=CGI/1.1" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[22] = "SERVER_NAME=localhost" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[23] = "SERVER_PORT=631" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[24] = "REMOTE_ADDR=127.0.0.1" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[25] = "REMOTE_HOST=localhost" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[26] = "SCRIPT_NAME=/admin/" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[27] = "SCRIPT_FILENAME=/usr/local/share/doc/cups/admin/" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[28] = "REMOTE_USER=root" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[29] = "SERVER_PROTOCOL=HTTP/1.1" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[30] = "HTTP_COOKIE=org.cups.sid=0aa85d9cb4e3ae5cb37e7c71d4faae78" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[31] = "HTTP_USER_AGENT=Mozilla/5.0 (X11; OpenBSD amd64; rv:33.0) Gecko/20100101 Firefox/33.0 SeaMonkey/2.30" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[32] = "REQUEST_METHOD=GET" D [03/Dec/2014:08:57:54 +0100] [CGI] envp[33] = "QUERY_STRING=OP=redirect&URL=/printers/HP_Deskjet_F4280" D [03/Dec/2014:08:57:54 +0100] cupsdAddCert: Adding certificate for PID 16731 D [03/Dec/2014:08:57:54 +0100] [CGI] Started /usr/local/libexec/cups/cgi-bin/admin.cgi (PID 16731) I [03/Dec/2014:08:57:54 +0100] [Client 77] Started "/usr/local/libexec/cups/cgi-bin/admin.cgi" (pid=16731, file=21) D [03/Dec/2014:08:57:54 +0100] [Client 77] Waiting for CGI data. D [03/Dec/2014:08:57:54 +0100] [CGI] admin.cgi started... D [03/Dec/2014:08:57:54 +0100] [Client 88] Accepted from localhost (Domain) D [03/Dec/2014:08:57:54 +0100] [Client 88] Waiting for request. D [03/Dec/2014:08:57:54 +0100] [CGI] http=0x328cf5af000 D [03/Dec/2014:08:57:54 +0100] [CGI] cgiSetVariable: SECTION="admin" D [03/Dec/2014:08:57:54 +0100] [CGI] cgiSetVariable: REFRESH_PAGE="" D [03/Dec/2014:08:57:54 +0100] [CGI] org.cups.sid cookie is "0aa85d9cb4e3ae5cb37e7c71d4faae78" D [03/Dec/2014:08:57:54 +0100] [CGI] cgiSetVariable: OP="redirect" D [03/Dec/2014:08:57:54 +0100] [CGI] cgiSetVariable: URL="/printers/HP_Deskjet_F4280" D [03/Dec/2014:08:57:54 +0100] [CGI] redirecting with prefix http://localhost:631! D [03/Dec/2014:08:57:54 +0100] [Client 88] HTTP_STATE_WAITING Closing for error 32 (Broken pipe) D [03/Dec/2014:08:57:54 +0100] [Client 88] Closing connection. D [03/Dec/2014:08:57:54 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files" D [03/Dec/2014:08:57:54 +0100] [Client 77] CGI data ready to be sent. D [03/Dec/2014:08:57:54 +0100] [Client 77] con->http=0xa3bfc0cb000 D [03/Dec/2014:08:57:54 +0100] [Client 77] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=0x0(), pipe_pid=16731, file=21 D [03/Dec/2014:08:57:54 +0100] [Client 77] Waiting for CGI data. D [03/Dec/2014:08:57:54 +0100] [Client 77] Script header: Location: http://localhost:631/printers/HP_Deskjet_F4280 D [03/Dec/2014:08:57:54 +0100] [Client 77] Script header: D [03/Dec/2014:08:57:54 +0100] [Client 77] Sending status 303 for CGI. D [03/Dec/2014:08:57:54 +0100] [Client 77] cupsdSendHeader: code=303, type="(null)", auth_type=0 D [03/Dec/2014:08:57:54 +0100] [Client 77] Flushing write buffer. D [03/Dec/2014:08:57:54 +0100] [Client 77] New state is HTTP_STATE_WAITING D [03/Dec/2014:08:57:54 +0100] [Client 77] Waiting for request. D [03/Dec/2014:08:57:54 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files" D [03/Dec/2014:08:57:54 +0100] PID 16731 (/usr/local/libexec/cups/cgi-bin/admin.cgi) was terminated normally with signal 15. D [03/Dec/2014:08:58:04 +0100] [Client 77] HTTP_STATE_WAITING Closing for error 32 (Broken pipe) D [03/Dec/2014:08:58:04 +0100] [Client 77] Closing connection. D [03/Dec/2014:08:58:04 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files" I [03/Dec/2014:08:58:13 +0100] Saving printers.conf... I [03/Dec/2014:08:58:13 +0100] Generating printcap /etc/cups/printcap... D [03/Dec/2014:08:58:13 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients and dirty files" D [03/Dec/2014:08:58:13 +0100] Report: clients=6 D [03/Dec/2014:08:58:13 +0100] Report: jobs=0 D [03/Dec/2014:08:58:13 +0100] Report: jobs-active=0 D [03/Dec/2014:08:58:13 +0100] Report: printers=2 D [03/Dec/2014:08:58:13 +0100] Report: stringpool-string-count=29032 D [03/Dec/2014:08:58:13 +0100] Report: stringpool-alloc-bytes=11792 D [03/Dec/2014:08:58:13 +0100] Report: stringpool-total-bytes=535152 Both the messages: D [03/Dec/2014:08:58:04 +0100] [Client 77] HTTP_STATE_WAITING Closing for error 32 (Broken pipe) D [03/Dec/2014:08:58:13 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients and dirty files" look suspicious, but I'm not able to debug further... Maybe it worths noting some "strange" permissions: just22@poseidon:[~]> ll /etc/cups/printers.conf -rw------- 1 root _cups 897B Dec 3 08:58 /etc/cups/printers.conf (not readable by _cups?) Thanks in advance for any hints -- Alessandro DE LAURENZIS [mailto:just22....@gmail.com] LinkedIn: http://it.linkedin.com/in/delaurenzis
