CUPS fails to find USB Printer

ToxygeneB · 2013-05-23 13:47:40

I've recently moved Arch away from a VM to become my main OS. I've got everything working except CUPS.

I have an Epson Stylus SX405 USB MFD. I followed the instructions at https://wiki.archlinux.org/index.php/CUPS and hooked up the printer. Using the CUPS web interface, Administration > Add Printer doesn't list the local USB printer (just some networking options) and Administration > Find New Printers results in "No Printers Found".

My user is in the lp group and the lp group is included in the SystemGroup line in /etc/cups/cups-files.conf (and I also tried using the root account to log into the web interface with the same result).

I have tried both with and without the usblp module blacklisted.

dmesg and lsusb both show the printer is recognised by the kernel. When using the usblp module /dev/usb/lp0 is created, and is owned by root:lp with permissions of crw-rw---- (as expected).

Any suggestions please?

I'm afraid nothing in the CUPS logs stands out but that may just be my lack of experience with CUPS (previous times I've used CUPS on other Linux distros it's just worked "out of the box").

lsusb output:

Bus 006 Device 006: ID 04b8:084a Seiko Epson Corp. PX-501A [Stylus NX400]

With usblp available, dmesg output:

[  230.343367] usb 6-1: new high-speed USB device number 3 using ehci-pci
[  230.671624] Initializing USB Mass Storage driver...
[  230.672556] usblp 6-1:1.1: usblp0: USB Bidirectional printer dev 3 if 1 alt 0 proto 2 vid 0x04B8 pid 0x084A
[  230.673207] usbcore: registered new interface driver usblp
[  230.681010] scsi6 : usb-storage 6-1:1.2
[  230.681169] usbcore: registered new interface driver usb-storage
[  230.681172] USB Mass Storage support registered.
[  231.686229] scsi 6:0:0:0: Direct-Access     EPSON    Stylus Storage   1.00 PQ: 0 ANSI: 2
[  231.694562] sd 6:0:0:0: [sdb] Attached SCSI removable disk

With usblp available, CUPS log:

D [23/May/2013:13:53:32 +0100] [Client 14] Accepted from localhost:631 (IPv6)
D [23/May/2013:13:53:32 +0100] Report: clients=1
D [23/May/2013:13:53:32 +0100] Report: jobs=0
D [23/May/2013:13:53:32 +0100] Report: jobs-active=0
D [23/May/2013:13:53:32 +0100] Report: printers=0
D [23/May/2013:13:53:32 +0100] Report: stringpool-string-count=416
D [23/May/2013:13:53:32 +0100] Report: stringpool-alloc-bytes=4896
D [23/May/2013:13:53:32 +0100] Report: stringpool-total-bytes=5912
D [23/May/2013:13:53:32 +0100] [Client 14] POST /admin/ HTTP/1.1
D [23/May/2013:13:53:32 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [23/May/2013:13:53:32 +0100] [Client 14] Authorized as root using Basic
D [23/May/2013:13:53:32 +0100] [CGI] argv[0] = "/usr/lib/cups/cgi-bin/admin.cgi"
D [23/May/2013:13:53:32 +0100] [CGI] envp[0] = "CUPS_CACHEDIR=/var/cache/cups"
D [23/May/2013:13:53:32 +0100] [CGI] envp[1] = "CUPS_DATADIR=/usr/share/cups"
D [23/May/2013:13:53:32 +0100] [CGI] envp[2] = "CUPS_DOCROOT=/usr/share/cups/doc"
D [23/May/2013:13:53:32 +0100] [CGI] envp[3] = "CUPS_FONTPATH=/usr/share/cups/fonts"
D [23/May/2013:13:53:32 +0100] [CGI] envp[4] = "CUPS_REQUESTROOT=/var/spool/cups"
D [23/May/2013:13:53:32 +0100] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/lib/cups"
D [23/May/2013:13:53:32 +0100] [CGI] envp[6] = "CUPS_SERVERROOT=/etc/cups"
D [23/May/2013:13:53:32 +0100] [CGI] envp[7] = "CUPS_STATEDIR=/var/run/cups"
D [23/May/2013:13:53:32 +0100] [CGI] envp[8] = "HOME=/var/spool/cups/tmp"
D [23/May/2013:13:53:32 +0100] [CGI] envp[9] = "PATH=/usr/lib/cups/filter:/usr/bin:/usr/bin:/bin:/usr/bin"
D [23/May/2013:13:53:32 +0100] [CGI] envp[10] = "SERVER_ADMIN=root@savage"
D [23/May/2013:13:53:32 +0100] [CGI] envp[11] = "SOFTWARE=CUPS/1.6.2"
D [23/May/2013:13:53:32 +0100] [CGI] envp[12] = "TMPDIR=/var/spool/cups/tmp"
D [23/May/2013:13:53:32 +0100] [CGI] envp[13] = "USER=root"
D [23/May/2013:13:53:32 +0100] [CGI] envp[14] = "CUPS_MAX_MESSAGE=2047"
D [23/May/2013:13:53:32 +0100] [CGI] envp[15] = "CUPS_SERVER=/var/run/cups/cups.sock"
D [23/May/2013:13:53:32 +0100] [CGI] envp[16] = "CUPS_ENCRYPTION=IfRequested"
D [23/May/2013:13:53:32 +0100] [CGI] envp[17] = "IPP_PORT=631"
D [23/May/2013:13:53:32 +0100] [CGI] envp[18] = "AUTH_TYPE=Basic"
D [23/May/2013:13:53:32 +0100] [CGI] envp[19] = "LANG=en_GB.UTF8"
D [23/May/2013:13:53:32 +0100] [CGI] envp[20] = "REDIRECT_STATUS=1"
D [23/May/2013:13:53:32 +0100] [CGI] envp[21] = "GATEWAY_INTERFACE=CGI/1.1"
D [23/May/2013:13:53:32 +0100] [CGI] envp[22] = "SERVER_NAME=localhost"
D [23/May/2013:13:53:32 +0100] [CGI] envp[23] = "SERVER_PORT=631"
D [23/May/2013:13:53:32 +0100] [CGI] envp[24] = "REMOTE_ADDR=[v1.::1]"
D [23/May/2013:13:53:32 +0100] [CGI] envp[25] = "REMOTE_HOST=localhost"
D [23/May/2013:13:53:32 +0100] [CGI] envp[26] = "SCRIPT_NAME=/admin/"
D [23/May/2013:13:53:32 +0100] [CGI] envp[27] = "SCRIPT_FILENAME=/usr/share/cups/doc/admin/"
D [23/May/2013:13:53:32 +0100] [CGI] envp[28] = "REMOTE_USER=root"
D [23/May/2013:13:53:32 +0100] [CGI] envp[29] = "SERVER_PROTOCOL=HTTP/1.1"
D [23/May/2013:13:53:32 +0100] [CGI] envp[30] = "HTTP_COOKIE=org.cups.sid=43bbffe4c241012de24e0364ad687226"
D [23/May/2013:13:53:32 +0100] [CGI] envp[31] = "HTTP_USER_AGENT=Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.31 (KHTML, like Gecko) Chrome/26.0.1410.63 Safari/537.31"
D [23/May/2013:13:53:32 +0100] [CGI] envp[32] = "HTTP_REFERER=http://localhost:631/admin"
D [23/May/2013:13:53:32 +0100] [CGI] envp[33] = "REQUEST_METHOD=POST"
D [23/May/2013:13:53:32 +0100] [CGI] envp[34] = "CONTENT_LENGTH=66"
D [23/May/2013:13:53:32 +0100] [CGI] envp[35] = "CONTENT_TYPE=application/x-www-form-urlencoded"
D [23/May/2013:13:53:32 +0100] [CGI] Started /usr/lib/cups/cgi-bin/admin.cgi (PID 1282)
I [23/May/2013:13:53:32 +0100] [Client 14] Started "/usr/lib/cups/cgi-bin/admin.cgi" (pid=1282)
D [23/May/2013:13:53:32 +0100] [Client 14] file=16
D [23/May/2013:13:53:32 +0100] [CGI] admin.cgi started...
D [23/May/2013:13:53:32 +0100] [Client 15] Accepted from localhost (Domain)
D [23/May/2013:13:53:32 +0100] [CGI] http=0x7f330637f3a0
D [23/May/2013:13:53:32 +0100] [CGI] cgiSetVariable: SECTION="admin"
D [23/May/2013:13:53:32 +0100] [CGI] cgiSetVariable: REFRESH_PAGE=""
D [23/May/2013:13:53:32 +0100] [CGI] org.cups.sid cookie is "43bbffe4c241012de24e0364ad687226"
D [23/May/2013:13:53:32 +0100] [CGI] cgiSetVariable: org.cups.sid="43bbffe4c241012de24e0364ad687226"
D [23/May/2013:13:53:32 +0100] [CGI] cgiSetVariable: OP="find-new-printers"
D [23/May/2013:13:53:32 +0100] [CGI] op="find-new-printers"...
D [23/May/2013:13:53:32 +0100] [CGI] cgiSetVariable: TITLE="List Available Printers"
D [23/May/2013:13:53:32 +0100] [CGI] cgiSetVariable: SERVER_NAME="localhost"
D [23/May/2013:13:53:32 +0100] [CGI] cgiSetVariable: REMOTE_USER="root"
D [23/May/2013:13:53:32 +0100] [CGI] cgiSetVariable: CUPS_VERSION="CUPS v1.6.2"
D [23/May/2013:13:53:32 +0100] Script header: Content-Type: text/html;charset=utf-8
D [23/May/2013:13:53:32 +0100] Script header: 
D [23/May/2013:13:53:32 +0100] [Client 15] POST / HTTP/1.1
D [23/May/2013:13:53:32 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [23/May/2013:13:53:32 +0100] [Client 15] No authentication data provided.
D [23/May/2013:13:53:32 +0100] [Client 15] 2.0 CUPS-Get-Printers 1
D [23/May/2013:13:53:32 +0100] CUPS-Get-Printers
D [23/May/2013:13:53:32 +0100] CUPS-Get-Printers client-error-not-found: No destinations added.
D [23/May/2013:13:53:32 +0100] Returning IPP client-error-not-found for CUPS-Get-Printers (no URI) from localhost
D [23/May/2013:13:53:32 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [23/May/2013:13:53:32 +0100] [Client 15] POST / HTTP/1.1
D [23/May/2013:13:53:32 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [23/May/2013:13:53:32 +0100] [Client 15] No authentication data provided.
D [23/May/2013:13:53:32 +0100] [Client 15] 2.0 CUPS-Get-Devices 2
D [23/May/2013:13:53:32 +0100] CUPS-Get-Devices
D [23/May/2013:13:53:32 +0100] cupsdIsAuthorized: username=""
D [23/May/2013:13:53:32 +0100] Returning HTTP Unauthorized for CUPS-Get-Devices (no URI) from localhost
D [23/May/2013:13:53:32 +0100] [Client 15] WWW-Authenticate: Basic realm="CUPS", trc="y"
D [23/May/2013:13:53:32 +0100] [Client 15] HTTP_WAITING Closing on EOF
D [23/May/2013:13:53:32 +0100] [Client 15] Closing connection.
D [23/May/2013:13:53:32 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [23/May/2013:13:53:32 +0100] [Client 15] Accepted from localhost (Domain)
D [23/May/2013:13:53:32 +0100] [Client 15] HTTP_WAITING Closing on EOF
D [23/May/2013:13:53:32 +0100] [Client 15] Closing connection.
D [23/May/2013:13:53:32 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [23/May/2013:13:53:32 +0100] [Client 15] Accepted from localhost (Domain)
D [23/May/2013:13:53:32 +0100] [Client 15] POST / HTTP/1.1
D [23/May/2013:13:53:32 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [23/May/2013:13:53:32 +0100] [Client 15] Authorized as root using Local
D [23/May/2013:13:53:32 +0100] [Client 15] 2.0 CUPS-Get-Devices 2
D [23/May/2013:13:53:32 +0100] CUPS-Get-Devices
D [23/May/2013:13:53:32 +0100] cupsdIsAuthorized: username="root"
D [23/May/2013:13:53:32 +0100] [CGI] argv[0] = "/usr/lib/cups/daemon/cups-deviced"
D [23/May/2013:13:53:32 +0100] [CGI] argv[1] = "2"
D [23/May/2013:13:53:32 +0100] [CGI] argv[2] = "0"
D [23/May/2013:13:53:32 +0100] [CGI] argv[3] = "15"
D [23/May/2013:13:53:32 +0100] [CGI] argv[4] = "2"
D [23/May/2013:13:53:32 +0100] [CGI] argv[5] = "requested-attributes=all"
D [23/May/2013:13:53:32 +0100] [CGI] envp[0] = "CUPS_CACHEDIR=/var/cache/cups"
D [23/May/2013:13:53:32 +0100] [CGI] envp[1] = "CUPS_DATADIR=/usr/share/cups"
D [23/May/2013:13:53:32 +0100] [CGI] envp[2] = "CUPS_DOCROOT=/usr/share/cups/doc"
D [23/May/2013:13:53:32 +0100] [CGI] envp[3] = "CUPS_FONTPATH=/usr/share/cups/fonts"
D [23/May/2013:13:53:32 +0100] [CGI] envp[4] = "CUPS_REQUESTROOT=/var/spool/cups"
D [23/May/2013:13:53:32 +0100] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/lib/cups"
D [23/May/2013:13:53:32 +0100] [CGI] envp[6] = "CUPS_SERVERROOT=/etc/cups"
D [23/May/2013:13:53:32 +0100] [CGI] envp[7] = "CUPS_STATEDIR=/var/run/cups"
D [23/May/2013:13:53:32 +0100] [CGI] envp[8] = "HOME=/var/spool/cups/tmp"
D [23/May/2013:13:53:32 +0100] [CGI] envp[9] = "PATH=/usr/lib/cups/filter:/usr/bin:/usr/bin:/bin:/usr/bin"
D [23/May/2013:13:53:32 +0100] [CGI] envp[10] = "SERVER_ADMIN=root@savage"
D [23/May/2013:13:53:32 +0100] [CGI] envp[11] = "SOFTWARE=CUPS/1.6.2"
D [23/May/2013:13:53:32 +0100] [CGI] envp[12] = "TMPDIR=/var/spool/cups/tmp"
D [23/May/2013:13:53:32 +0100] [CGI] envp[13] = "USER=root"
D [23/May/2013:13:53:32 +0100] [CGI] envp[14] = "CUPS_MAX_MESSAGE=2047"
D [23/May/2013:13:53:32 +0100] [CGI] envp[15] = "CUPS_SERVER=/var/run/cups/cups.sock"
D [23/May/2013:13:53:32 +0100] [CGI] envp[16] = "CUPS_ENCRYPTION=IfRequested"
D [23/May/2013:13:53:32 +0100] [CGI] envp[17] = "IPP_PORT=631"
D [23/May/2013:13:53:32 +0100] [CGI] envp[18] = "AUTH_TYPE=Local"
D [23/May/2013:13:53:32 +0100] [CGI] envp[19] = "LANG=en_GB.UTF8"
D [23/May/2013:13:53:32 +0100] [CGI] envp[20] = "REDIRECT_STATUS=1"
D [23/May/2013:13:53:32 +0100] [CGI] envp[21] = "GATEWAY_INTERFACE=CGI/1.1"
D [23/May/2013:13:53:32 +0100] [CGI] envp[22] = "SERVER_NAME=localhost"
D [23/May/2013:13:53:32 +0100] [CGI] envp[23] = "SERVER_PORT=631"
D [23/May/2013:13:53:32 +0100] [CGI] envp[24] = "REMOTE_ADDR=localhost"
D [23/May/2013:13:53:32 +0100] [CGI] envp[25] = "REMOTE_HOST=localhost"
D [23/May/2013:13:53:32 +0100] [CGI] envp[26] = "SCRIPT_NAME=/"
D [23/May/2013:13:53:32 +0100] [CGI] envp[27] = "SCRIPT_FILENAME=/usr/share/cups/doc/"
D [23/May/2013:13:53:32 +0100] [CGI] envp[28] = "REMOTE_USER=root"
D [23/May/2013:13:53:32 +0100] [CGI] envp[29] = "SERVER_PROTOCOL=HTTP/1.1"
D [23/May/2013:13:53:32 +0100] [CGI] envp[30] = "HTTP_USER_AGENT=CUPS/1.6.2 (Linux 3.9.3-1-ARCH; x86_64) IPP/2.0"
D [23/May/2013:13:53:32 +0100] [CGI] envp[31] = "REQUEST_METHOD=POST"
D [23/May/2013:13:53:32 +0100] [CGI] envp[32] = "CONTENT_LENGTH=75"
D [23/May/2013:13:53:32 +0100] [CGI] envp[33] = "CONTENT_TYPE=application/ipp"
D [23/May/2013:13:53:32 +0100] [CGI] Started /usr/lib/cups/daemon/cups-deviced (PID 1283)
I [23/May/2013:13:53:32 +0100] [Client 15] Started "/usr/lib/cups/daemon/cups-deviced" (pid=1283)
D [23/May/2013:13:53:32 +0100] [Client 15] file=17
D [23/May/2013:13:53:32 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/serial (PID 1284)
D [23/May/2013:13:53:32 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/lpd (PID 1285)
D [23/May/2013:13:53:32 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/parallel (PID 1286)
D [23/May/2013:13:53:32 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/https (PID 1287)
D [23/May/2013:13:53:32 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/dnssd (PID 1288)
D [23/May/2013:13:53:32 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/socket (PID 1289)
D [23/May/2013:13:53:32 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/ipps (PID 1290)
D [23/May/2013:13:53:32 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/usb (PID 1291)
D [23/May/2013:13:53:32 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/http (PID 1292)
D [23/May/2013:13:53:32 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/ipp (PID 1293)
D [23/May/2013:13:53:32 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/smb (PID 1294)
D [23/May/2013:13:53:32 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/snmp (PID 1295)
D [23/May/2013:13:53:32 +0100] [cups-deviced] PID 1286 (parallel) exited with no errors.
D [23/May/2013:13:53:32 +0100] Script header: Content-Type: application/ipp
D [23/May/2013:13:53:32 +0100] Script header: 
D [23/May/2013:13:53:32 +0100] [CGI] Flushed attributes...
D [23/May/2013:13:53:32 +0100] [cups-deviced] Found device "https"...
D [23/May/2013:13:53:32 +0100] [cups-deviced] PID 1287 (https) exited with no errors.
D [23/May/2013:13:53:32 +0100] [CGI] Flushed attributes...
D [23/May/2013:13:53:32 +0100] [cups-deviced] Found device "ipps"...
D [23/May/2013:13:53:32 +0100] [CGI] Flushed attributes...
D [23/May/2013:13:53:32 +0100] [cups-deviced] Found device "http"...
D [23/May/2013:13:53:32 +0100] [cups-deviced] PID 1292 (http) exited with no errors.
D [23/May/2013:13:53:32 +0100] [CGI] No address specified and no Address line in /etc/cups/snmp.conf...
D [23/May/2013:13:53:32 +0100] [cups-deviced] PID 1290 (ipps) exited with no errors.
D [23/May/2013:13:53:32 +0100] [cups-deviced] PID 1289 (socket) exited with no errors.
D [23/May/2013:13:53:32 +0100] [cups-deviced] PID 1295 (snmp) exited with no errors.
D [23/May/2013:13:53:32 +0100] [CGI] Flushed attributes...
D [23/May/2013:13:53:32 +0100] [cups-deviced] Found device "socket"...
D [23/May/2013:13:53:32 +0100] [CGI] Flushed attributes...
D [23/May/2013:13:53:32 +0100] [cups-deviced] Found device "ipp"...
D [23/May/2013:13:53:32 +0100] [cups-deviced] PID 1293 (ipp) exited with no errors.
D [23/May/2013:13:53:32 +0100] [CGI] list_devices
D [23/May/2013:13:53:32 +0100] [CGI] Flushed attributes...
D [23/May/2013:13:53:32 +0100] [cups-deviced] Found device "lpd"...
D [23/May/2013:13:53:32 +0100] [cups-deviced] PID 1285 (lpd) exited with no errors.
D [23/May/2013:13:53:32 +0100] [CGI] libusb_get_device_list=13
D [23/May/2013:13:53:32 +0100] [CGI] Failed to open device, code: -3
D [23/May/2013:13:53:32 +0100] [cups-deviced] PID 1284 (serial) exited with no errors.
D [23/May/2013:13:53:32 +0100] [CGI] Flushed attributes...
D [23/May/2013:13:53:32 +0100] [cups-deviced] Found device "smb"...
D [23/May/2013:13:53:32 +0100] [cups-deviced] PID 1294 (smb) exited with no errors.
D [23/May/2013:13:53:32 +0100] [cups-deviced] PID 1291 (usb) exited with no errors.
D [23/May/2013:13:53:32 +0100] [CGI] sent=0, count=0
D [23/May/2013:13:53:32 +0100] [cups-deviced] PID 1288 (dnssd) exited with no errors.
D [23/May/2013:13:53:32 +0100] PID 1283 (/usr/lib/cups/daemon/cups-deviced) exited with no errors.
D [23/May/2013:13:53:32 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [23/May/2013:13:53:32 +0100] [Client 15] HTTP_WAITING Closing on EOF
D [23/May/2013:13:53:32 +0100] [Client 15] Closing connection.
D [23/May/2013:13:53:32 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [23/May/2013:13:53:32 +0100] PID 1282 (/usr/lib/cups/cgi-bin/admin.cgi) exited with no errors.
D [23/May/2013:13:53:32 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"

With usblp blacklisted, dmesg output:

[ 1800.275619] usb 6-1: USB disconnect, device number 4
[ 1824.759893] usb 6-1: new high-speed USB device number 5 using ehci-pci
[ 1824.906619] scsi8 : usb-storage 6-1:1.2
[ 1825.912774] scsi 8:0:0:0: Direct-Access     EPSON    Stylus Storage   1.00 PQ: 0 ANSI: 2
[ 1825.921026] sd 8:0:0:0: [sdb] Attached SCSI removable disk

With usblp blacklisted, CUPS log:

D [23/May/2013:14:43:53 +0100] [Client 14] GET /admin/ HTTP/1.1
D [23/May/2013:14:43:53 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [23/May/2013:14:43:53 +0100] [Client 14] Authorized as root using Basic
D [23/May/2013:14:43:53 +0100] [CGI] argv[0] = "/usr/lib/cups/cgi-bin/admin.cgi"
D [23/May/2013:14:43:53 +0100] [CGI] envp[0] = "CUPS_CACHEDIR=/var/cache/cups"
D [23/May/2013:14:43:53 +0100] [CGI] envp[1] = "CUPS_DATADIR=/usr/share/cups"
D [23/May/2013:14:43:53 +0100] [CGI] envp[2] = "CUPS_DOCROOT=/usr/share/cups/doc"
D [23/May/2013:14:43:53 +0100] [CGI] envp[3] = "CUPS_FONTPATH=/usr/share/cups/fonts"
D [23/May/2013:14:43:53 +0100] [CGI] envp[4] = "CUPS_REQUESTROOT=/var/spool/cups"
D [23/May/2013:14:43:53 +0100] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/lib/cups"
D [23/May/2013:14:43:53 +0100] [CGI] envp[6] = "CUPS_SERVERROOT=/etc/cups"
D [23/May/2013:14:43:53 +0100] [CGI] envp[7] = "CUPS_STATEDIR=/var/run/cups"
D [23/May/2013:14:43:53 +0100] [CGI] envp[8] = "HOME=/var/spool/cups/tmp"
D [23/May/2013:14:43:53 +0100] [CGI] envp[9] = "PATH=/usr/lib/cups/filter:/usr/bin:/usr/bin:/bin:/usr/bin"
D [23/May/2013:14:43:53 +0100] [CGI] envp[10] = "SERVER_ADMIN=root@savage"
D [23/May/2013:14:43:53 +0100] [CGI] envp[11] = "SOFTWARE=CUPS/1.6.2"
D [23/May/2013:14:43:53 +0100] [CGI] envp[12] = "TMPDIR=/var/spool/cups/tmp"
D [23/May/2013:14:43:53 +0100] [CGI] envp[13] = "USER=root"
D [23/May/2013:14:43:53 +0100] [CGI] envp[14] = "CUPS_MAX_MESSAGE=2047"
D [23/May/2013:14:43:53 +0100] [CGI] envp[15] = "CUPS_SERVER=/var/run/cups/cups.sock"
D [23/May/2013:14:43:53 +0100] [CGI] envp[16] = "CUPS_ENCRYPTION=IfRequested"
D [23/May/2013:14:43:53 +0100] [CGI] envp[17] = "IPP_PORT=631"
D [23/May/2013:14:43:53 +0100] [CGI] envp[18] = "AUTH_TYPE=Basic"
D [23/May/2013:14:43:53 +0100] [CGI] envp[19] = "LANG=en_GB.UTF8"
D [23/May/2013:14:43:53 +0100] [CGI] envp[20] = "REDIRECT_STATUS=1"
D [23/May/2013:14:43:53 +0100] [CGI] envp[21] = "GATEWAY_INTERFACE=CGI/1.1"
D [23/May/2013:14:43:53 +0100] [CGI] envp[22] = "SERVER_NAME=localhost"
D [23/May/2013:14:43:53 +0100] [CGI] envp[23] = "SERVER_PORT=631"
D [23/May/2013:14:43:53 +0100] [CGI] envp[24] = "REMOTE_ADDR=[v1.::1]"
D [23/May/2013:14:43:53 +0100] [CGI] envp[25] = "REMOTE_HOST=localhost"
D [23/May/2013:14:43:53 +0100] [CGI] envp[26] = "SCRIPT_NAME=/admin/"
D [23/May/2013:14:43:53 +0100] [CGI] envp[27] = "SCRIPT_FILENAME=/usr/share/cups/doc/admin/"
D [23/May/2013:14:43:53 +0100] [CGI] envp[28] = "REMOTE_USER=root"
D [23/May/2013:14:43:53 +0100] [CGI] envp[29] = "SERVER_PROTOCOL=HTTP/1.1"
D [23/May/2013:14:43:53 +0100] [CGI] envp[30] = "HTTP_COOKIE=org.cups.sid=43bbffe4c241012de24e0364ad687226"
D [23/May/2013:14:43:53 +0100] [CGI] envp[31] = "HTTP_USER_AGENT=Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.31 (KHTML, like Gecko) Chrome/26.0.1410.63 Safari/537.31"
D [23/May/2013:14:43:53 +0100] [CGI] envp[32] = "REQUEST_METHOD=GET"
D [23/May/2013:14:43:53 +0100] [CGI] envp[33] = "QUERY_STRING="
D [23/May/2013:14:43:53 +0100] [CGI] Started /usr/lib/cups/cgi-bin/admin.cgi (PID 1794)
I [23/May/2013:14:43:53 +0100] [Client 14] Started "/usr/lib/cups/cgi-bin/admin.cgi" (pid=1794)
D [23/May/2013:14:43:53 +0100] [Client 14] file=15
D [23/May/2013:14:43:53 +0100] [CGI] admin.cgi started...
D [23/May/2013:14:43:53 +0100] [Client 16] Accepted from localhost (Domain)
D [23/May/2013:14:43:53 +0100] [CGI] http=0x7f165970d3a0
D [23/May/2013:14:43:53 +0100] [CGI] cgiSetVariable: SECTION="admin"
D [23/May/2013:14:43:53 +0100] [CGI] cgiSetVariable: REFRESH_PAGE=""
D [23/May/2013:14:43:53 +0100] [CGI] org.cups.sid cookie is "43bbffe4c241012de24e0364ad687226"
D [23/May/2013:14:43:53 +0100] [CGI] No form data, showing main menu...
D [23/May/2013:14:43:53 +0100] [CGI] cgiSetVariable: DEBUG_LOGGING="CHECKED"
D [23/May/2013:14:43:53 +0100] [CGI] cgiSetVariable: USER_CANCEL_ANY="CHECKED"
D [23/May/2013:14:43:53 +0100] [CGI] cgiSetVariable: HAVE_GSSAPI="1"
D [23/May/2013:14:43:53 +0100] [CGI] cgiSetVariable: KERBEROS=""
D [23/May/2013:14:43:53 +0100] [CGI] cgiSetVariable: PRESERVE_JOBS="CHECKED"
D [23/May/2013:14:43:53 +0100] [CGI] cgiSetVariable: PRESERVE_JOB_HISTORY="Yes"
D [23/May/2013:14:43:53 +0100] [CGI] cgiSetVariable: PRESERVE_JOB_FILES="1d"
D [23/May/2013:14:43:53 +0100] [CGI] cgiSetVariable: MAX_CLIENTS="100"
D [23/May/2013:14:43:53 +0100] [CGI] cgiSetVariable: MAX_JOBS="500"
D [23/May/2013:14:43:53 +0100] [CGI] cgiSetVariable: MAX_LOG_SIZE="1m"
D [23/May/2013:14:43:53 +0100] [CGI] /usr/share/cups/drivers/pscript5.dll: No such file or directory
D [23/May/2013:14:43:53 +0100] [Client 16] POST / HTTP/1.1
D [23/May/2013:14:43:53 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [23/May/2013:14:43:53 +0100] [Client 16] No authentication data provided.
D [23/May/2013:14:43:53 +0100] [Client 16] 2.0 Get-Subscriptions 1
D [23/May/2013:14:43:53 +0100] Get-Subscriptions ipp://localhost/
D [23/May/2013:14:43:53 +0100] Get-Subscriptions client-error-not-found: No subscriptions found.
D [23/May/2013:14:43:53 +0100] Returning IPP client-error-not-found for Get-Subscriptions (ipp://localhost/) from localhost
D [23/May/2013:14:43:53 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [23/May/2013:14:43:53 +0100] [CGI] cgiSetVariable: SERVER_NAME="localhost"
D [23/May/2013:14:43:53 +0100] [CGI] cgiSetVariable: REMOTE_USER="root"
D [23/May/2013:14:43:53 +0100] [CGI] cgiSetVariable: CUPS_VERSION="CUPS v1.6.2"
D [23/May/2013:14:43:53 +0100] [CGI] cgiSetVariable: TITLE="Administration"
D [23/May/2013:14:43:53 +0100] [CGI] cgiSetVariable: SERVER_NAME="localhost"
D [23/May/2013:14:43:53 +0100] [CGI] cgiSetVariable: REMOTE_USER="root"
D [23/May/2013:14:43:53 +0100] [CGI] cgiSetVariable: CUPS_VERSION="CUPS v1.6.2"
D [23/May/2013:14:43:53 +0100] Script header: Content-Type: text/html;charset=utf-8
D [23/May/2013:14:43:53 +0100] Script header: 
D [23/May/2013:14:43:53 +0100] [Client 16] HTTP_WAITING Closing on EOF
D [23/May/2013:14:43:53 +0100] [Client 16] Closing connection.
D [23/May/2013:14:43:53 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [23/May/2013:14:43:53 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [23/May/2013:14:43:53 +0100] PID 1794 (/usr/lib/cups/cgi-bin/admin.cgi) exited with no errors.
D [23/May/2013:14:43:55 +0100] [Client 14] POST /admin/ HTTP/1.1
D [23/May/2013:14:43:55 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [23/May/2013:14:43:55 +0100] [Client 14] Authorized as root using Basic
D [23/May/2013:14:43:55 +0100] [CGI] argv[0] = "/usr/lib/cups/cgi-bin/admin.cgi"
D [23/May/2013:14:43:55 +0100] [CGI] envp[0] = "CUPS_CACHEDIR=/var/cache/cups"
D [23/May/2013:14:43:55 +0100] [CGI] envp[1] = "CUPS_DATADIR=/usr/share/cups"
D [23/May/2013:14:43:55 +0100] [CGI] envp[2] = "CUPS_DOCROOT=/usr/share/cups/doc"
D [23/May/2013:14:43:55 +0100] [CGI] envp[3] = "CUPS_FONTPATH=/usr/share/cups/fonts"
D [23/May/2013:14:43:55 +0100] [CGI] envp[4] = "CUPS_REQUESTROOT=/var/spool/cups"
D [23/May/2013:14:43:55 +0100] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/lib/cups"
D [23/May/2013:14:43:55 +0100] [CGI] envp[6] = "CUPS_SERVERROOT=/etc/cups"
D [23/May/2013:14:43:55 +0100] [CGI] envp[7] = "CUPS_STATEDIR=/var/run/cups"
D [23/May/2013:14:43:55 +0100] [CGI] envp[8] = "HOME=/var/spool/cups/tmp"
D [23/May/2013:14:43:55 +0100] [CGI] envp[9] = "PATH=/usr/lib/cups/filter:/usr/bin:/usr/bin:/bin:/usr/bin"
D [23/May/2013:14:43:55 +0100] [CGI] envp[10] = "SERVER_ADMIN=root@savage"
D [23/May/2013:14:43:55 +0100] [CGI] envp[11] = "SOFTWARE=CUPS/1.6.2"
D [23/May/2013:14:43:55 +0100] [CGI] envp[12] = "TMPDIR=/var/spool/cups/tmp"
D [23/May/2013:14:43:55 +0100] [CGI] envp[13] = "USER=root"
D [23/May/2013:14:43:55 +0100] [CGI] envp[14] = "CUPS_MAX_MESSAGE=2047"
D [23/May/2013:14:43:55 +0100] [CGI] envp[15] = "CUPS_SERVER=/var/run/cups/cups.sock"
D [23/May/2013:14:43:55 +0100] [CGI] envp[16] = "CUPS_ENCRYPTION=IfRequested"
D [23/May/2013:14:43:55 +0100] [CGI] envp[17] = "IPP_PORT=631"
D [23/May/2013:14:43:55 +0100] [CGI] envp[18] = "AUTH_TYPE=Basic"
D [23/May/2013:14:43:55 +0100] [CGI] envp[19] = "LANG=en_GB.UTF8"
D [23/May/2013:14:43:55 +0100] [CGI] envp[20] = "REDIRECT_STATUS=1"
D [23/May/2013:14:43:55 +0100] [CGI] envp[21] = "GATEWAY_INTERFACE=CGI/1.1"
D [23/May/2013:14:43:55 +0100] [CGI] envp[22] = "SERVER_NAME=localhost"
D [23/May/2013:14:43:55 +0100] [CGI] envp[23] = "SERVER_PORT=631"
D [23/May/2013:14:43:55 +0100] [CGI] envp[24] = "REMOTE_ADDR=[v1.::1]"
D [23/May/2013:14:43:55 +0100] [CGI] envp[25] = "REMOTE_HOST=localhost"
D [23/May/2013:14:43:55 +0100] [CGI] envp[26] = "SCRIPT_NAME=/admin/"
D [23/May/2013:14:43:55 +0100] [CGI] envp[27] = "SCRIPT_FILENAME=/usr/share/cups/doc/admin/"
D [23/May/2013:14:43:55 +0100] [CGI] envp[28] = "REMOTE_USER=root"
D [23/May/2013:14:43:55 +0100] [CGI] envp[29] = "SERVER_PROTOCOL=HTTP/1.1"
D [23/May/2013:14:43:55 +0100] [CGI] envp[30] = "HTTP_COOKIE=org.cups.sid=43bbffe4c241012de24e0364ad687226"
D [23/May/2013:14:43:55 +0100] [CGI] envp[31] = "HTTP_USER_AGENT=Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.31 (KHTML, like Gecko) Chrome/26.0.1410.63 Safari/537.31"
D [23/May/2013:14:43:55 +0100] [CGI] envp[32] = "HTTP_REFERER=http://localhost:631/admin/"
D [23/May/2013:14:43:55 +0100] [CGI] envp[33] = "REQUEST_METHOD=POST"
D [23/May/2013:14:43:55 +0100] [CGI] envp[34] = "CONTENT_LENGTH=66"
D [23/May/2013:14:43:55 +0100] [CGI] envp[35] = "CONTENT_TYPE=application/x-www-form-urlencoded"
D [23/May/2013:14:43:55 +0100] [CGI] Started /usr/lib/cups/cgi-bin/admin.cgi (PID 1795)
I [23/May/2013:14:43:55 +0100] [Client 14] Started "/usr/lib/cups/cgi-bin/admin.cgi" (pid=1795)
D [23/May/2013:14:43:55 +0100] [Client 14] file=16
D [23/May/2013:14:43:55 +0100] [CGI] admin.cgi started...
D [23/May/2013:14:43:55 +0100] [Client 15] Accepted from localhost (Domain)
D [23/May/2013:14:43:55 +0100] [CGI] http=0x7f4cf7abd3a0
D [23/May/2013:14:43:55 +0100] [CGI] cgiSetVariable: SECTION="admin"
D [23/May/2013:14:43:55 +0100] [CGI] cgiSetVariable: REFRESH_PAGE=""
D [23/May/2013:14:43:55 +0100] [CGI] org.cups.sid cookie is "43bbffe4c241012de24e0364ad687226"
D [23/May/2013:14:43:55 +0100] [CGI] cgiSetVariable: org.cups.sid="43bbffe4c241012de24e0364ad687226"
D [23/May/2013:14:43:55 +0100] [CGI] cgiSetVariable: OP="find-new-printers"
D [23/May/2013:14:43:55 +0100] [CGI] op="find-new-printers"...
D [23/May/2013:14:43:55 +0100] [CGI] cgiSetVariable: TITLE="List Available Printers"
D [23/May/2013:14:43:55 +0100] [CGI] cgiSetVariable: SERVER_NAME="localhost"
D [23/May/2013:14:43:55 +0100] [CGI] cgiSetVariable: REMOTE_USER="root"
D [23/May/2013:14:43:55 +0100] [CGI] cgiSetVariable: CUPS_VERSION="CUPS v1.6.2"
D [23/May/2013:14:43:55 +0100] [Client 15] POST / HTTP/1.1
D [23/May/2013:14:43:55 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [23/May/2013:14:43:55 +0100] [Client 15] No authentication data provided.
D [23/May/2013:14:43:55 +0100] Script header: Content-Type: text/html;charset=utf-8
D [23/May/2013:14:43:55 +0100] Script header: 
D [23/May/2013:14:43:55 +0100] [Client 15] 2.0 CUPS-Get-Printers 1
D [23/May/2013:14:43:55 +0100] CUPS-Get-Printers
D [23/May/2013:14:43:55 +0100] CUPS-Get-Printers client-error-not-found: No destinations added.
D [23/May/2013:14:43:55 +0100] Returning IPP client-error-not-found for CUPS-Get-Printers (no URI) from localhost
D [23/May/2013:14:43:55 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [23/May/2013:14:43:55 +0100] [Client 15] POST / HTTP/1.1
D [23/May/2013:14:43:55 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [23/May/2013:14:43:55 +0100] [Client 15] No authentication data provided.
D [23/May/2013:14:43:55 +0100] [Client 15] 2.0 CUPS-Get-Devices 2
D [23/May/2013:14:43:55 +0100] CUPS-Get-Devices
D [23/May/2013:14:43:55 +0100] cupsdIsAuthorized: username=""
D [23/May/2013:14:43:55 +0100] Returning HTTP Unauthorized for CUPS-Get-Devices (no URI) from localhost
D [23/May/2013:14:43:55 +0100] [Client 15] WWW-Authenticate: Basic realm="CUPS", trc="y"
D [23/May/2013:14:43:55 +0100] [Client 15] HTTP_WAITING Closing on EOF
D [23/May/2013:14:43:55 +0100] [Client 15] Closing connection.
D [23/May/2013:14:43:55 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [23/May/2013:14:43:55 +0100] [Client 15] Accepted from localhost (Domain)
D [23/May/2013:14:43:55 +0100] [Client 15] HTTP_WAITING Closing on EOF
D [23/May/2013:14:43:55 +0100] [Client 15] Closing connection.
D [23/May/2013:14:43:55 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [23/May/2013:14:43:55 +0100] [Client 15] Accepted from localhost (Domain)
D [23/May/2013:14:43:55 +0100] [Client 15] POST / HTTP/1.1
D [23/May/2013:14:43:55 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [23/May/2013:14:43:55 +0100] [Client 15] Authorized as root using Local
D [23/May/2013:14:43:55 +0100] [Client 15] 2.0 CUPS-Get-Devices 2
D [23/May/2013:14:43:55 +0100] CUPS-Get-Devices
D [23/May/2013:14:43:55 +0100] cupsdIsAuthorized: username="root"
D [23/May/2013:14:43:55 +0100] [CGI] argv[0] = "/usr/lib/cups/daemon/cups-deviced"
D [23/May/2013:14:43:55 +0100] [CGI] argv[1] = "2"
D [23/May/2013:14:43:55 +0100] [CGI] argv[2] = "0"
D [23/May/2013:14:43:55 +0100] [CGI] argv[3] = "15"
D [23/May/2013:14:43:55 +0100] [CGI] argv[4] = "2"
D [23/May/2013:14:43:55 +0100] [CGI] argv[5] = "requested-attributes=all"
D [23/May/2013:14:43:55 +0100] [CGI] envp[0] = "CUPS_CACHEDIR=/var/cache/cups"
D [23/May/2013:14:43:55 +0100] [CGI] envp[1] = "CUPS_DATADIR=/usr/share/cups"
D [23/May/2013:14:43:55 +0100] [CGI] envp[2] = "CUPS_DOCROOT=/usr/share/cups/doc"
D [23/May/2013:14:43:55 +0100] [CGI] envp[3] = "CUPS_FONTPATH=/usr/share/cups/fonts"
D [23/May/2013:14:43:55 +0100] [CGI] envp[4] = "CUPS_REQUESTROOT=/var/spool/cups"
D [23/May/2013:14:43:55 +0100] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/lib/cups"
D [23/May/2013:14:43:55 +0100] [CGI] envp[6] = "CUPS_SERVERROOT=/etc/cups"
D [23/May/2013:14:43:55 +0100] [CGI] envp[7] = "CUPS_STATEDIR=/var/run/cups"
D [23/May/2013:14:43:55 +0100] [CGI] envp[8] = "HOME=/var/spool/cups/tmp"
D [23/May/2013:14:43:55 +0100] [CGI] envp[9] = "PATH=/usr/lib/cups/filter:/usr/bin:/usr/bin:/bin:/usr/bin"
D [23/May/2013:14:43:55 +0100] [CGI] envp[10] = "SERVER_ADMIN=root@savage"
D [23/May/2013:14:43:55 +0100] [CGI] envp[11] = "SOFTWARE=CUPS/1.6.2"
D [23/May/2013:14:43:55 +0100] [CGI] envp[12] = "TMPDIR=/var/spool/cups/tmp"
D [23/May/2013:14:43:55 +0100] [CGI] envp[13] = "USER=root"
D [23/May/2013:14:43:55 +0100] [CGI] envp[14] = "CUPS_MAX_MESSAGE=2047"
D [23/May/2013:14:43:55 +0100] [CGI] envp[15] = "CUPS_SERVER=/var/run/cups/cups.sock"
D [23/May/2013:14:43:55 +0100] [CGI] envp[16] = "CUPS_ENCRYPTION=IfRequested"
D [23/May/2013:14:43:55 +0100] [CGI] envp[17] = "IPP_PORT=631"
D [23/May/2013:14:43:55 +0100] [CGI] envp[18] = "AUTH_TYPE=Local"
D [23/May/2013:14:43:55 +0100] [CGI] envp[19] = "LANG=en_GB.UTF8"
D [23/May/2013:14:43:55 +0100] [CGI] envp[20] = "REDIRECT_STATUS=1"
D [23/May/2013:14:43:55 +0100] [CGI] envp[21] = "GATEWAY_INTERFACE=CGI/1.1"
D [23/May/2013:14:43:55 +0100] [CGI] envp[22] = "SERVER_NAME=localhost"
D [23/May/2013:14:43:55 +0100] [CGI] envp[23] = "SERVER_PORT=631"
D [23/May/2013:14:43:55 +0100] [CGI] envp[24] = "REMOTE_ADDR=localhost"
D [23/May/2013:14:43:55 +0100] [CGI] envp[25] = "REMOTE_HOST=localhost"
D [23/May/2013:14:43:55 +0100] [CGI] envp[26] = "SCRIPT_NAME=/"
D [23/May/2013:14:43:55 +0100] [CGI] envp[27] = "SCRIPT_FILENAME=/usr/share/cups/doc/"
D [23/May/2013:14:43:55 +0100] [CGI] envp[28] = "REMOTE_USER=root"
D [23/May/2013:14:43:55 +0100] [CGI] envp[29] = "SERVER_PROTOCOL=HTTP/1.1"
D [23/May/2013:14:43:55 +0100] [CGI] envp[30] = "HTTP_USER_AGENT=CUPS/1.6.2 (Linux 3.9.3-1-ARCH; x86_64) IPP/2.0"
D [23/May/2013:14:43:55 +0100] [CGI] envp[31] = "REQUEST_METHOD=POST"
D [23/May/2013:14:43:55 +0100] [CGI] envp[32] = "CONTENT_LENGTH=75"
D [23/May/2013:14:43:55 +0100] [CGI] envp[33] = "CONTENT_TYPE=application/ipp"
D [23/May/2013:14:43:55 +0100] [CGI] Started /usr/lib/cups/daemon/cups-deviced (PID 1796)
I [23/May/2013:14:43:55 +0100] [Client 15] Started "/usr/lib/cups/daemon/cups-deviced" (pid=1796)
D [23/May/2013:14:43:55 +0100] [Client 15] file=17
D [23/May/2013:14:43:55 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/serial (PID 1797)
D [23/May/2013:14:43:55 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/lpd (PID 1798)
D [23/May/2013:14:43:55 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/parallel (PID 1799)
D [23/May/2013:14:43:55 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/https (PID 1800)
D [23/May/2013:14:43:55 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/dnssd (PID 1801)
D [23/May/2013:14:43:55 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/socket (PID 1802)
D [23/May/2013:14:43:55 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/ipps (PID 1803)
D [23/May/2013:14:43:55 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/usb (PID 1804)
D [23/May/2013:14:43:55 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/http (PID 1805)
D [23/May/2013:14:43:55 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/ipp (PID 1806)
D [23/May/2013:14:43:55 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/smb (PID 1807)
D [23/May/2013:14:43:55 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/snmp (PID 1808)
D [23/May/2013:14:43:55 +0100] Script header: Content-Type: application/ipp
D [23/May/2013:14:43:55 +0100] Script header: 
D [23/May/2013:14:43:55 +0100] [CGI] Flushed attributes...
D [23/May/2013:14:43:55 +0100] [cups-deviced] Found device "https"...
D [23/May/2013:14:43:55 +0100] [CGI] Flushed attributes...
D [23/May/2013:14:43:55 +0100] [cups-deviced] Found device "socket"...
D [23/May/2013:14:43:55 +0100] [cups-deviced] PID 1802 (socket) exited with no errors.
D [23/May/2013:14:43:55 +0100] [CGI] Flushed attributes...
D [23/May/2013:14:43:55 +0100] [cups-deviced] Found device "lpd"...
D [23/May/2013:14:43:55 +0100] [CGI] Flushed attributes...
D [23/May/2013:14:43:55 +0100] [cups-deviced] Found device "ipps"...
D [23/May/2013:14:43:55 +0100] [cups-deviced] PID 1797 (serial) exited with no errors.
D [23/May/2013:14:43:55 +0100] [cups-deviced] PID 1798 (lpd) exited with no errors.
D [23/May/2013:14:43:55 +0100] [cups-deviced] PID 1799 (parallel) exited with no errors.
D [23/May/2013:14:43:55 +0100] [cups-deviced] PID 1800 (https) exited with no errors.
D [23/May/2013:14:43:55 +0100] [cups-deviced] PID 1803 (ipps) exited with no errors.
D [23/May/2013:14:43:55 +0100] [CGI] Flushed attributes...
D [23/May/2013:14:43:55 +0100] [cups-deviced] Found device "ipp"...
D [23/May/2013:14:43:55 +0100] [CGI] No address specified and no Address line in /etc/cups/snmp.conf...
D [23/May/2013:14:43:55 +0100] [CGI] Flushed attributes...
D [23/May/2013:14:43:55 +0100] [cups-deviced] Found device "http"...
D [23/May/2013:14:43:55 +0100] [cups-deviced] PID 1806 (ipp) exited with no errors.
D [23/May/2013:14:43:55 +0100] [cups-deviced] PID 1805 (http) exited with no errors.
D [23/May/2013:14:43:55 +0100] [CGI] list_devices
D [23/May/2013:14:43:55 +0100] [CGI] libusb_get_device_list=13
D [23/May/2013:14:43:55 +0100] [CGI] Failed to open device, code: -3
D [23/May/2013:14:43:55 +0100] [cups-deviced] PID 1808 (snmp) exited with no errors.
D [23/May/2013:14:43:55 +0100] [CGI] Flushed attributes...
D [23/May/2013:14:43:55 +0100] [cups-deviced] Found device "smb"...
D [23/May/2013:14:43:55 +0100] [cups-deviced] PID 1807 (smb) exited with no errors.
D [23/May/2013:14:43:55 +0100] [cups-deviced] PID 1804 (usb) exited with no errors.
D [23/May/2013:14:43:55 +0100] [CGI] sent=0, count=0
D [23/May/2013:14:43:55 +0100] [cups-deviced] PID 1801 (dnssd) exited with no errors.
D [23/May/2013:14:43:55 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [23/May/2013:14:43:55 +0100] [Client 15] HTTP_WAITING Closing on EOF
D [23/May/2013:14:43:55 +0100] [Client 15] Closing connection.
D [23/May/2013:14:43:55 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [23/May/2013:14:43:55 +0100] PID 1796 (/usr/lib/cups/daemon/cups-deviced) exited with no errors.
D [23/May/2013:14:43:55 +0100] PID 1795 (/usr/lib/cups/cgi-bin/admin.cgi) exited with no errors.
D [23/May/2013:14:43:55 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"

ToxygeneB · 2013-05-23 18:24:13

$ /usr/lib/cups/backend/usb

DEBUG: list_devices
DEBUG: libusb_get_device_list=14
DEBUG2: Printer found with device ID: MFG:EPSON;CMD:ESCPL2,BDC,D4,D4PX,ESCPR1;MDL:Stylus SX400;CLS:PRINTER;DES:EPSON Stylus SX400; Device URI: usb://EPSON/Stylus%20SX400?serial=4B5757503032303544&interface=1
direct usb://EPSON/Stylus%20SX400?serial=4B5757503032303544&interface=1 "EPSON Stylus SX400" "EPSON Stylus SX400" "MFG:EPSON;CMD:ESCPL2,BDC,D4,D4PX,ESCPR1;MDL:Stylus SX400;CLS:PRINTER;DES:EPSON Stylus SX400;" ""

So CUPS is recognising the printer but it's not appearing in the web interface or KDE's Printer KCM.

ToxygeneB · 2013-05-23 19:57:43

Added the printer from the command line:

lpadmin -p SX405 -E -v "usb://EPSON/Stylus%20SX400?serial=4B5757503032303544" -P /usr/share/cups/model/C/stp-escp2-sx405.5.2.ppd.gz

Checked the device permissions for the device node and they're:

crw-rw----+ 1 root lp   189, 771 May 23 20:35 /dev/bus/usb/007/004

But CUPS gives the error "Waiting for printer to become available" in the web interface whenever I try to print anything.

chibe · 2014-10-09 16:09:56

I had the same issue with my printer and it *was* cured by fixing the permissions of the usb device (android-udev thought my printer was a phone ).

PS:
usblp was not a problem

Last edited by chibe (2014-10-09 16:11:10)

Arch Linux

#1 2013-05-23 13:47:40

CUPS fails to find USB Printer

#2 2013-05-23 18:24:13

Re: CUPS fails to find USB Printer

#3 2013-05-23 19:57:43

Re: CUPS fails to find USB Printer

#4 2014-10-09 16:09:56

Re: CUPS fails to find USB Printer

Board footer