[cups] Print jobs pausing queue

Fri Jan 22 09:44:55 PST 2016

We have debugging turned on for our CUPS server, but the print queue keeps pausing on this one printer and we can’t figure it out.  Our clients are starting to get upset over it.  And now this same problem seems to be happening with another printer queue as well.  The weird thing is if they delete and re-add the computer on their client machine, it sometimes fixes the problem and then they can print again.  But it seems every hour it will stop printing and the queue will pause on it’s own and then they sometimes can delete and re-add the printer on their client computer and it will work again.  Yet the print job is making it to the queue on the server and the server is doing the pausing. So it makes no sense to me what is happening.  We have two identical printers on our campus.  One printer is on one CUPS server, and we have the other printer on another CUPS server.  One works great with no problems to our clients and the other is constantly pausing he queue whenever certain print jobs are sent to it and we can’t figure out what is the cause.  The error log doesn’t make sense to what it’s having the problem with and we know the printer does work fine if you print directly to it without the print server.  I have a section of the log file below to see if maybe you can help us identify the problem because it seems to be getting worse and ticking off our clients.  The Printer is a Konica Minolta BizHub C5501 with a Fiery Unit attached to it for processing.  Any help you can provide would be most appreciative.

Brian

D [22/Jan/2016:09:30:00 -0800] [Client 1088901] con->http=0x7fcca6958000
D [22/Jan/2016:09:30:00 -0800] [Client 1088901] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=75, response=0x7fcca3dc40a0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [22/Jan/2016:09:30:00 -0800] [Client 1088901] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [22/Jan/2016:09:30:00 -0800] [Client 1088901] bytes=0, http_state=0, data_remaining=75
D [22/Jan/2016:09:30:00 -0800] [Client 1088901] Flushing write buffer.
D [22/Jan/2016:09:30:00 -0800] [Client 1088901] New state is HTTP_STATE_WAITING
D [22/Jan/2016:09:30:00 -0800] [Client 1088901] Waiting for request.
D [22/Jan/2016:09:30:00 -0800] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:00 -0800] [Client 1088901] POST /printers/Cat-Media-Bizhub-C5501 HTTP/1.1
D [22/Jan/2016:09:30:00 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [22/Jan/2016:09:30:00 -0800] [Client 1088901] Read: status=200
D [22/Jan/2016:09:30:00 -0800] [Client 1088901] No authentication data provided.
D [22/Jan/2016:09:30:00 -0800] [Client 1088901] Read: status=100
D [22/Jan/2016:09:30:00 -0800] [Client 1088901] 2.0 Get-Printer-Attributes 342
D [22/Jan/2016:09:30:00 -0800] Get-Printer-Attributes ipps://Cat-Printserver.local.:631/printers/Cat-Media-Bizhub-C5501
D [22/Jan/2016:09:30:00 -0800] [Client 1088901] Returning IPP successful-ok for Get-Printer-Attributes (ipps://Cat-Printserver.local.:631/printers/Cat-Media-Bizhub-C5501) from [v1.fe80::6e40:8ff:feb8:dcbe+en0]
D [22/Jan/2016:09:30:00 -0800] [Client 1088901] Content-Length: 2448
D [22/Jan/2016:09:30:00 -0800] [Client 1088901] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [22/Jan/2016:09:30:00 -0800] [Client 1088901] con->http=0x7fcca6958000
D [22/Jan/2016:09:30:00 -0800] [Client 1088901] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2448, response=0x7fcca6400000(IPP_STATE_DATA), pipe_pid=0, file=-1
D [22/Jan/2016:09:30:00 -0800] [Client 1088901] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [22/Jan/2016:09:30:00 -0800] [Client 1088901] bytes=0, http_state=0, data_remaining=2448
D [22/Jan/2016:09:30:00 -0800] [Client 1088901] Flushing write buffer.
D [22/Jan/2016:09:30:00 -0800] [Client 1088901] New state is HTTP_STATE_WAITING
D [22/Jan/2016:09:30:00 -0800] [Client 1088901] Waiting for request.
D [22/Jan/2016:09:30:00 -0800] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] GET /admin HTTP/1.1
D [22/Jan/2016:09:30:00 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] Read: status=200
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] No authentication data provided.
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] Processing GET /admin
D [22/Jan/2016:09:30:00 -0800] [CGI] argv[0] = "/usr/libexec/cups/cgi-bin/admin.cgi"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[0] = "<CFProcessPath>"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[1] = "CUPS_CACHEDIR=/private/var/spool/cups/cache"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[2] = "CUPS_DATADIR=/usr/share/cups"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[3] = "CUPS_DOCROOT=/usr/share/doc/cups"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[4] = "CUPS_FONTPATH=/usr/share/cups/fonts"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[5] = "CUPS_REQUESTROOT=/private/var/spool/cups"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[6] = "CUPS_SERVERBIN=/usr/libexec/cups"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[7] = "CUPS_SERVERROOT=/private/etc/cups"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[8] = "CUPS_STATEDIR=/private/etc/cups"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[9] = "HOME=/private/var/spool/cups/tmp"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[10] = "PATH=/usr/libexec/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[11] = "SERVER_ADMIN=root at localhost"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[12] = "SOFTWARE=CUPS/2.1.0"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[13] = "TMPDIR=/private/var/spool/cups/tmp"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[14] = "USER=root"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[15] = "CUPS_MAX_MESSAGE=2047"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[16] = "CUPS_SERVER=/private/var/run/cupsd"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[17] = "CUPS_ENCRYPTION=IfRequested"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[18] = "IPP_PORT=631"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[19] = "LANG=en_US.UTF8"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[20] = "REDIRECT_STATUS=1"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[21] = "GATEWAY_INTERFACE=CGI/1.1"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[22] = "SERVER_NAME=localhost"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[23] = "SERVER_PORT=631"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[24] = "REMOTE_ADDR=[v1.::1]"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[25] = "REMOTE_HOST=localhost"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[26] = "SCRIPT_NAME=/admin"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[27] = "SCRIPT_FILENAME=/usr/share/doc/cups/admin"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[28] = "SERVER_PROTOCOL=HTTP/1.1"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[29] = "HTTP_COOKIE=org.cups.sid=123b223607a15b0aa7ba63a51b8219c7"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[30] = "HTTP_USER_AGENT=Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_2) AppleWebKit/601.3.9 (KHTML, like Gecko) Version/9.0.2 Safari/601.3.9"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[31] = "HTTP_REFERER=http://localhost:631/printers/Cat-Media-Bizhub-C5501"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[32] = "REQUEST_METHOD=GET"
D [22/Jan/2016:09:30:00 -0800] [CGI] envp[33] = "QUERY_STRING="
D [22/Jan/2016:09:30:00 -0800] [CGI] Started /usr/libexec/cups/cgi-bin/admin.cgi (PID 44602)
I [22/Jan/2016:09:30:00 -0800] [Client 1088861] Started "/usr/libexec/cups/cgi-bin/admin.cgi" (pid=44602, file=21)
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] Waiting for CGI data.
D [22/Jan/2016:09:30:00 -0800] [CGI] admin.cgi started...
D [22/Jan/2016:09:30:00 -0800] [Client 1088911] Accepted from localhost (Domain admin.cgi[44602])
D [22/Jan/2016:09:30:00 -0800] [Client 1088911] Waiting for request.
D [22/Jan/2016:09:30:00 -0800] [CGI] http=0x7f8b1b809800
D [22/Jan/2016:09:30:00 -0800] [CGI] cgiSetVariable: SECTION="admin"
D [22/Jan/2016:09:30:00 -0800] [CGI] cgiSetVariable: REFRESH_PAGE=""
D [22/Jan/2016:09:30:00 -0800] [CGI] org.cups.sid cookie is "123b223607a15b0aa7ba63a51b8219c7"
D [22/Jan/2016:09:30:00 -0800] [CGI] No form data, showing main menu...
D [22/Jan/2016:09:30:00 -0800] [CGI] cgiSetVariable: DEBUG_LOGGING="CHECKED"
D [22/Jan/2016:09:30:00 -0800] [CGI] cgiSetVariable: REMOTE_ADMIN="CHECKED"
D [22/Jan/2016:09:30:00 -0800] [CGI] cgiSetVariable: REMOTE_ANY="CHECKED"
D [22/Jan/2016:09:30:00 -0800] [CGI] cgiSetVariable: SHARE_PRINTERS="CHECKED"
D [22/Jan/2016:09:30:00 -0800] [CGI] cgiSetVariable: USER_CANCEL_ANY="CHECKED"
D [22/Jan/2016:09:30:00 -0800] [CGI] cgiSetVariable: HAVE_GSSAPI="1"
D [22/Jan/2016:09:30:00 -0800] [CGI] cgiSetVariable: KERBEROS=""
D [22/Jan/2016:09:30:00 -0800] [CGI] cgiSetVariable: BROWSE_WEB_IF="CHECKED"
D [22/Jan/2016:09:30:00 -0800] [CGI] cgiSetVariable: PRESERVE_JOBS="CHECKED"
D [22/Jan/2016:09:30:00 -0800] [CGI] cgiSetVariable: PRESERVE_JOB_HISTORY="Yes"
D [22/Jan/2016:09:30:00 -0800] [CGI] cgiSetVariable: PRESERVE_JOB_FILES="1d"
D [22/Jan/2016:09:30:00 -0800] [CGI] cgiSetVariable: MAX_CLIENTS="100"
D [22/Jan/2016:09:30:00 -0800] [CGI] cgiSetVariable: MAX_JOBS="500"
D [22/Jan/2016:09:30:00 -0800] [CGI] cgiSetVariable: MAX_LOG_SIZE="1m"
D [22/Jan/2016:09:30:00 -0800] [CGI] /usr/share/cups/drivers/pscript5.dll: No such file or directory
D [22/Jan/2016:09:30:00 -0800] [Client 1088911] POST / HTTP/1.1
D [22/Jan/2016:09:30:00 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:00 -0800] [Client 1088911] Read: status=200
D [22/Jan/2016:09:30:00 -0800] [Client 1088911] No authentication data provided.
D [22/Jan/2016:09:30:00 -0800] [Client 1088911] 2.0 Get-Subscriptions 1
D [22/Jan/2016:09:30:00 -0800] Get-Subscriptions ipp://localhost/
D [22/Jan/2016:09:30:00 -0800] Get-Subscriptions client-error-not-found: No subscriptions found.
D [22/Jan/2016:09:30:00 -0800] [Client 1088911] Returning IPP client-error-not-found for Get-Subscriptions (ipp://localhost/) from localhost
D [22/Jan/2016:09:30:00 -0800] [Client 1088911] Content-Length: 117
D [22/Jan/2016:09:30:00 -0800] [Client 1088911] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [22/Jan/2016:09:30:00 -0800] [Client 1088911] con->http=0x7fcca4889400
D [22/Jan/2016:09:30:00 -0800] [Client 1088911] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=117, response=0x7fcca3e1af70(IPP_STATE_DATA), pipe_pid=0, file=-1
D [22/Jan/2016:09:30:00 -0800] [Client 1088911] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [22/Jan/2016:09:30:00 -0800] [Client 1088911] bytes=0, http_state=0, data_remaining=117
D [22/Jan/2016:09:30:00 -0800] [Client 1088911] Flushing write buffer.
D [22/Jan/2016:09:30:00 -0800] [Client 1088911] New state is HTTP_STATE_WAITING
D [22/Jan/2016:09:30:00 -0800] [Client 1088911] Waiting for request.
D [22/Jan/2016:09:30:00 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:00 -0800] [CGI] cgiSetVariable: SERVER_NAME="localhost"
D [22/Jan/2016:09:30:00 -0800] [CGI] cgiSetVariable: CUPS_VERSION="CUPS v2.1.0"
D [22/Jan/2016:09:30:00 -0800] [CGI] cgiSetVariable: TITLE="Administration"
D [22/Jan/2016:09:30:00 -0800] [CGI] cgiSetVariable: SERVER_NAME="localhost"
D [22/Jan/2016:09:30:00 -0800] [CGI] cgiSetVariable: CUPS_VERSION="CUPS v2.1.0"
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] CGI data ready to be sent.
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] con->http=0x7fcca40f3c00
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=0x0(), pipe_pid=44602, file=21
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] Waiting for CGI data.
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] Script header: Content-Type: text/html;charset=utf-8
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] Script header: 
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] Sending status 200 for CGI.
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] cupsdSendHeader: code=200, type="(null)", auth_type=0
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] con->http=0x7fcca40f3c00
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0x0(), pipe_pid=44602, file=21
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] Waiting for CGI data.
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] CGI data ready to be sent.
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] con->http=0x7fcca40f3c00
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0x0(), pipe_pid=44602, file=21
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] Waiting for CGI data.
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] con->http=0x7fcca40f3c00
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0x0(), pipe_pid=44602, file=21
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] Waiting for CGI data.
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] CGI data ready to be sent.
D [22/Jan/2016:09:30:00 -0800] [Client 1088911] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [22/Jan/2016:09:30:00 -0800] [Client 1088911] Closing connection.
D [22/Jan/2016:09:30:00 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] con->http=0x7fcca40f3c00
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0x0(), pipe_pid=44602, file=21
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] Waiting for CGI data.
D [22/Jan/2016:09:30:00 -0800] PID 44602 (/usr/libexec/cups/cgi-bin/admin.cgi) exited with no errors.
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] con->http=0x7fcca40f3c00
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0x0(), pipe_pid=44602, file=21
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] Waiting for CGI data.
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] CGI data ready to be sent.
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] con->http=0x7fcca40f3c00
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0x0(), pipe_pid=44602, file=21
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] Waiting for CGI data.
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] con->http=0x7fcca40f3c00
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0x0(), pipe_pid=44602, file=21
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] Waiting for CGI data.
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] CGI data ready to be sent.
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] con->http=0x7fcca40f3c00
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0x0(), pipe_pid=44602, file=21
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] Waiting for CGI data.
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] Sending 0-length chunk.
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] Flushing write buffer.
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] New state is HTTP_STATE_WAITING
D [22/Jan/2016:09:30:00 -0800] [Client 1088861] Waiting for request.
D [22/Jan/2016:09:30:00 -0800] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:01 -0800] [Client 1088912] Accepted from 192.168.161.107:64540 (IPv4)
D [22/Jan/2016:09:30:01 -0800] [Client 1088912] Waiting for request.
I [22/Jan/2016:09:30:01 -0800] [Client 1088912] Connection now encrypted.
D [22/Jan/2016:09:30:01 -0800] [Client 1088912] POST /printers/Cat-Media-Bizhub-C5501 HTTP/1.1
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [22/Jan/2016:09:30:01 -0800] [Client 1088912] Read: status=200
D [22/Jan/2016:09:30:01 -0800] [Client 1088912] No authentication data provided.
D [22/Jan/2016:09:30:01 -0800] [Client 1088892] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [22/Jan/2016:09:30:01 -0800] [Client 1088892] Closing connection.
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:01 -0800] [Client 1088913] Accepted from localhost (Domain fieryd[44603])
D [22/Jan/2016:09:30:01 -0800] [Client 1088913] Waiting for request.
D [22/Jan/2016:09:30:01 -0800] [Client 1088913] POST / HTTP/1.1
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:01 -0800] [Client 1088913] Read: status=200
D [22/Jan/2016:09:30:01 -0800] [Client 1088913] No authentication data provided.
D [22/Jan/2016:09:30:01 -0800] [Client 1088913] 2.0 CUPS-Get-Printers 1
D [22/Jan/2016:09:30:01 -0800] CUPS-Get-Printers
D [22/Jan/2016:09:30:01 -0800] [Client 1088913] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [22/Jan/2016:09:30:01 -0800] [Client 1088913] Content-Length: 7508
D [22/Jan/2016:09:30:01 -0800] [Client 1088913] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [22/Jan/2016:09:30:01 -0800] [Client 1088913] con->http=0x7fcca5d92600
D [22/Jan/2016:09:30:01 -0800] [Client 1088913] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=7508, response=0x7fcca3c1d150(IPP_STATE_DATA), pipe_pid=0, file=-1
D [22/Jan/2016:09:30:01 -0800] [Client 1088913] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [22/Jan/2016:09:30:01 -0800] [Client 1088913] bytes=0, http_state=0, data_remaining=7508
D [22/Jan/2016:09:30:01 -0800] [Client 1088913] Flushing write buffer.
D [22/Jan/2016:09:30:01 -0800] [Client 1088913] New state is HTTP_STATE_WAITING
D [22/Jan/2016:09:30:01 -0800] [Client 1088913] Waiting for request.
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:01 -0800] [Client 1088913] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [22/Jan/2016:09:30:01 -0800] [Client 1088913] Closing connection.
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:01 -0800] [Client 1088914] Accepted from localhost (Domain fieryd[44603])
D [22/Jan/2016:09:30:01 -0800] [Client 1088914] Waiting for request.
D [22/Jan/2016:09:30:01 -0800] [Client 1088914] POST / HTTP/1.1
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:01 -0800] [Client 1088914] Read: status=200
D [22/Jan/2016:09:30:01 -0800] [Client 1088914] No authentication data provided.
D [22/Jan/2016:09:30:01 -0800] [Client 1088914] 2.0 CUPS-Get-Default 2
D [22/Jan/2016:09:30:01 -0800] CUPS-Get-Default
D [22/Jan/2016:09:30:01 -0800] CUPS-Get-Default client-error-not-found: No default printer.
D [22/Jan/2016:09:30:01 -0800] [Client 1088914] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
D [22/Jan/2016:09:30:01 -0800] [Client 1088914] Content-Length: 113
D [22/Jan/2016:09:30:01 -0800] [Client 1088914] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [22/Jan/2016:09:30:01 -0800] [Client 1088914] con->http=0x7fcca5d92600
D [22/Jan/2016:09:30:01 -0800] [Client 1088914] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=113, response=0x7fcca3fd6180(IPP_STATE_DATA), pipe_pid=0, file=-1
D [22/Jan/2016:09:30:01 -0800] [Client 1088914] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [22/Jan/2016:09:30:01 -0800] [Client 1088914] bytes=0, http_state=0, data_remaining=113
D [22/Jan/2016:09:30:01 -0800] [Client 1088914] Flushing write buffer.
D [22/Jan/2016:09:30:01 -0800] [Client 1088914] New state is HTTP_STATE_WAITING
D [22/Jan/2016:09:30:01 -0800] [Client 1088914] Waiting for request.
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:01 -0800] [Client 1088915] Accepted from localhost (Domain lpstat[44604])
D [22/Jan/2016:09:30:01 -0800] [Client 1088915] Waiting for request.
D [22/Jan/2016:09:30:01 -0800] [Client 1088915] POST / HTTP/1.1
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:01 -0800] [Client 1088915] Read: status=200
D [22/Jan/2016:09:30:01 -0800] [Client 1088915] No authentication data provided.
D [22/Jan/2016:09:30:01 -0800] [Client 1088915] 2.0 CUPS-Get-Printers 1
D [22/Jan/2016:09:30:01 -0800] CUPS-Get-Printers
D [22/Jan/2016:09:30:01 -0800] [Client 1088915] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [22/Jan/2016:09:30:01 -0800] [Client 1088915] Content-Length: 7508
D [22/Jan/2016:09:30:01 -0800] [Client 1088915] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [22/Jan/2016:09:30:01 -0800] [Client 1088915] con->http=0x7fcca5dace00
D [22/Jan/2016:09:30:01 -0800] [Client 1088915] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=7508, response=0x7fcca3c21210(IPP_STATE_DATA), pipe_pid=0, file=-1
D [22/Jan/2016:09:30:01 -0800] [Client 1088915] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [22/Jan/2016:09:30:01 -0800] [Client 1088915] bytes=0, http_state=0, data_remaining=7508
D [22/Jan/2016:09:30:01 -0800] [Client 1088915] Flushing write buffer.
D [22/Jan/2016:09:30:01 -0800] [Client 1088915] New state is HTTP_STATE_WAITING
D [22/Jan/2016:09:30:01 -0800] [Client 1088915] Waiting for request.
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:01 -0800] [Client 1088915] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [22/Jan/2016:09:30:01 -0800] [Client 1088915] Closing connection.
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:01 -0800] [Client 1088916] Accepted from localhost (Domain lpstat[44604])
D [22/Jan/2016:09:30:01 -0800] [Client 1088916] Waiting for request.
D [22/Jan/2016:09:30:01 -0800] [Client 1088916] POST / HTTP/1.1
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:01 -0800] [Client 1088916] Read: status=200
D [22/Jan/2016:09:30:01 -0800] [Client 1088916] No authentication data provided.
D [22/Jan/2016:09:30:01 -0800] [Client 1088916] 2.0 CUPS-Get-Default 2
D [22/Jan/2016:09:30:01 -0800] CUPS-Get-Default
D [22/Jan/2016:09:30:01 -0800] CUPS-Get-Default client-error-not-found: No default printer.
D [22/Jan/2016:09:30:01 -0800] [Client 1088916] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
D [22/Jan/2016:09:30:01 -0800] [Client 1088916] Content-Length: 113
D [22/Jan/2016:09:30:01 -0800] [Client 1088916] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [22/Jan/2016:09:30:01 -0800] [Client 1088916] con->http=0x7fcca6954c00
D [22/Jan/2016:09:30:01 -0800] [Client 1088916] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=113, response=0x7fcca3d9d390(IPP_STATE_DATA), pipe_pid=0, file=-1
D [22/Jan/2016:09:30:01 -0800] [Client 1088916] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [22/Jan/2016:09:30:01 -0800] [Client 1088916] bytes=0, http_state=0, data_remaining=113
D [22/Jan/2016:09:30:01 -0800] [Client 1088916] Flushing write buffer.
D [22/Jan/2016:09:30:01 -0800] [Client 1088916] New state is HTTP_STATE_WAITING
D [22/Jan/2016:09:30:01 -0800] [Client 1088916] Waiting for request.
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:01 -0800] [Client 1088916] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [22/Jan/2016:09:30:01 -0800] [Client 1088916] Closing connection.
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:01 -0800] [Client 1088917] Accepted from localhost (Domain lpstat[44604])
D [22/Jan/2016:09:30:01 -0800] [Client 1088917] Waiting for request.
D [22/Jan/2016:09:30:01 -0800] [Client 1088917] POST / HTTP/1.1
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:01 -0800] [Client 1088917] Read: status=200
D [22/Jan/2016:09:30:01 -0800] [Client 1088917] No authentication data provided.
D [22/Jan/2016:09:30:01 -0800] [Client 1088917] 2.0 CUPS-Get-Printers 3
D [22/Jan/2016:09:30:01 -0800] CUPS-Get-Printers
D [22/Jan/2016:09:30:01 -0800] [Client 1088917] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [22/Jan/2016:09:30:01 -0800] [Client 1088917] Content-Length: 566
D [22/Jan/2016:09:30:01 -0800] [Client 1088917] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [22/Jan/2016:09:30:01 -0800] [Client 1088917] con->http=0x7fcca6954c00
D [22/Jan/2016:09:30:01 -0800] [Client 1088917] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=566, response=0x7fcca6454220(IPP_STATE_DATA), pipe_pid=0, file=-1
D [22/Jan/2016:09:30:01 -0800] [Client 1088917] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [22/Jan/2016:09:30:01 -0800] [Client 1088917] bytes=0, http_state=0, data_remaining=566
D [22/Jan/2016:09:30:01 -0800] [Client 1088917] Flushing write buffer.
D [22/Jan/2016:09:30:01 -0800] [Client 1088917] New state is HTTP_STATE_WAITING
D [22/Jan/2016:09:30:01 -0800] [Client 1088917] Waiting for request.
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:01 -0800] [Client 1088917] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [22/Jan/2016:09:30:01 -0800] [Client 1088917] Closing connection.
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:01 -0800] [Client 1088909] POST /printers/Cat-Media-Bizhub-C5501 HTTP/1.1
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:01 -0800] [Client 1088909] Read: status=200
D [22/Jan/2016:09:30:01 -0800] [Client 1088909] No authentication data provided.
D [22/Jan/2016:09:30:01 -0800] [Client 1088909] 2.0 Get-Printer-Attributes 193
D [22/Jan/2016:09:30:01 -0800] Get-Printer-Attributes ipps://Cat-Printserver.local.:631/printers/Cat-Media-Bizhub-C5501
D [22/Jan/2016:09:30:01 -0800] [Client 1088909] Returning IPP successful-ok for Get-Printer-Attributes (ipps://Cat-Printserver.local.:631/printers/Cat-Media-Bizhub-C5501) from 192.168.161.34
D [22/Jan/2016:09:30:01 -0800] [Client 1088909] Content-Length: 2448
D [22/Jan/2016:09:30:01 -0800] [Client 1088909] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] Accepted from 192.168.161.34:49578 (IPv4)
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] Waiting for request.
D [22/Jan/2016:09:30:01 -0800] [Client 1088909] con->http=0x7fcca4881800
D [22/Jan/2016:09:30:01 -0800] [Client 1088909] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2448, response=0x7fcca3e212b0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [22/Jan/2016:09:30:01 -0800] [Client 1088909] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [22/Jan/2016:09:30:01 -0800] [Client 1088909] bytes=0, http_state=0, data_remaining=2448
D [22/Jan/2016:09:30:01 -0800] [Client 1088909] Flushing write buffer.
D [22/Jan/2016:09:30:01 -0800] [Client 1088909] New state is HTTP_STATE_WAITING
D [22/Jan/2016:09:30:01 -0800] [Client 1088909] Waiting for request.
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
I [22/Jan/2016:09:30:01 -0800] [Client 1088918] Connection now encrypted.
D [22/Jan/2016:09:30:01 -0800] [Client 1088909] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [22/Jan/2016:09:30:01 -0800] [Client 1088909] Closing connection.
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:01 -0800] [Client 1088909] Waiting for socket close.
D [22/Jan/2016:09:30:01 -0800] [Client 1088919] Accepted from 192.168.161.34:49579 (IPv4)
D [22/Jan/2016:09:30:01 -0800] [Client 1088919] Waiting for request.
D [22/Jan/2016:09:30:01 -0800] [Client 1088909] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [22/Jan/2016:09:30:01 -0800] [Client 1088909] Closing connection.
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
I [22/Jan/2016:09:30:01 -0800] [Client 1088919] Connection now encrypted.
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] POST /printers/Cat-Media-Bizhub-C5501 HTTP/1.1
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] Read: status=200
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] No authentication data provided.
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] 2.0 Get-Printer-Attributes 195
D [22/Jan/2016:09:30:01 -0800] Get-Printer-Attributes ipps://Cat-Printserver.local.:631/printers/Cat-Media-Bizhub-C5501
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] Returning IPP successful-ok for Get-Printer-Attributes (ipps://Cat-Printserver.local.:631/printers/Cat-Media-Bizhub-C5501) from 192.168.161.34
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] Content-Length: 2448
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] con->http=0x7fcca5dace00
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2448, response=0x7fcca3c21240(IPP_STATE_DATA), pipe_pid=0, file=-1
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] bytes=0, http_state=0, data_remaining=2448
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] Flushing write buffer.
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] New state is HTTP_STATE_WAITING
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] Waiting for request.
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:01 -0800] [Client 1088919] POST /printers/Cat-Media-Bizhub-C5501 HTTP/1.1
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:01 -0800] [Client 1088919] Read: status=200
D [22/Jan/2016:09:30:01 -0800] [Client 1088919] No authentication data provided.
D [22/Jan/2016:09:30:01 -0800] [Client 1088919] 2.0 Get-Job-Attributes 194
D [22/Jan/2016:09:30:01 -0800] Get-Job-Attributes ipps://Cat-Printserver.local.:631/printers/Cat-Media-Bizhub-C5501
D [22/Jan/2016:09:30:01 -0800] [Client 1088919] Returning IPP successful-ok for Get-Job-Attributes (ipps://Cat-Printserver.local.:631/printers/Cat-Media-Bizhub-C5501) from 192.168.161.34
D [22/Jan/2016:09:30:01 -0800] [Client 1088919] Content-Length: 355
D [22/Jan/2016:09:30:01 -0800] [Client 1088919] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [22/Jan/2016:09:30:01 -0800] [Client 1088919] con->http=0x7fcca6954c00
D [22/Jan/2016:09:30:01 -0800] [Client 1088919] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=355, response=0x7fcca3f390e0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [22/Jan/2016:09:30:01 -0800] [Client 1088919] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [22/Jan/2016:09:30:01 -0800] [Client 1088919] bytes=0, http_state=0, data_remaining=355
D [22/Jan/2016:09:30:01 -0800] [Client 1088919] Flushing write buffer.
D [22/Jan/2016:09:30:01 -0800] [Client 1088919] New state is HTTP_STATE_WAITING
D [22/Jan/2016:09:30:01 -0800] [Client 1088919] Waiting for request.
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] POST /printers/Cat-Media-Bizhub-C5501 HTTP/1.1
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] Read: status=200
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] No authentication data provided.
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] 2.0 Get-Job-Attributes 196
D [22/Jan/2016:09:30:01 -0800] Get-Job-Attributes ipps://Cat-Printserver.local.:631/printers/Cat-Media-Bizhub-C5501
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] Returning IPP successful-ok for Get-Job-Attributes (ipps://Cat-Printserver.local.:631/printers/Cat-Media-Bizhub-C5501) from 192.168.161.34
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] Content-Length: 355
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] con->http=0x7fcca5dace00
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=355, response=0x7fcca3e212b0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] bytes=0, http_state=0, data_remaining=355
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] Flushing write buffer.
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] New state is HTTP_STATE_WAITING
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] Waiting for request.
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] Closing connection.
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] Waiting for socket close.
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [22/Jan/2016:09:30:01 -0800] [Client 1088918] Closing connection.
D [22/Jan/2016:09:30:01 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:02 -0800] [Client 1088901] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [22/Jan/2016:09:30:02 -0800] [Client 1088901] Closing connection.
D [22/Jan/2016:09:30:02 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:02 -0800] [Client 1088901] Waiting for socket close.
D [22/Jan/2016:09:30:02 -0800] [Client 1088901] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [22/Jan/2016:09:30:02 -0800] [Client 1088901] Closing connection.
D [22/Jan/2016:09:30:02 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:02 -0800] [Client 1088861] GET /admin/log/error_log? HTTP/1.1
D [22/Jan/2016:09:30:02 -0800] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [22/Jan/2016:09:30:02 -0800] [Client 1088861] Read: status=200
D [22/Jan/2016:09:30:02 -0800] [Client 1088861] No authentication data provided.
D [22/Jan/2016:09:30:02 -0800] [Client 1088861] Processing GET /admin/log/error_log?

> On Jan 20, 2016, at 12:17 PM, Michael Weghorn <m.weghorn at posteo.de> wrote:
> 
> Hello Brian,
> 
> in order to further examine the problem, it might help to set the
> LogLevel to "Debug" in "cupsd.conf" (if you haven't done so yet). CUPS
> needs to be restarted for this to take effect.
> 
> Then, the log file "error_log" should contain further information, e.g.
> it should be possible to find out which filters are used an which filter
> fails. Possibly, you will also find helpful information on the cause of
> the problem.
> 
> What I would try to do to find the cause is to find one file with which
> you can reproduce this filter error and then look closely at the error_log.
> 
> You can also run the CUPS filters manually using the tool "cupsfilter".
> 
> Possibly, the following links could help you to further look into the
> issue, even if you are not using Debian GNU/Linux (also have a look at
> the "cupsfilter" related links at the end of the article):
> https://wiki.debian.org/Dissecting%20and%20Debugging%20the%20CUPS%20Printing%20System
> 
> Which kind of system are you running and which CUPS version is in use?
> 
> Best regards,
> Michael
> 
> On 2016-01-19 22:10, Brian Corbin wrote:
>> Thanks for responding Michael.  What we experience is certain print jobs get sent and sometimes they give a filter error in the log file. Those are the jobs that then pause the queue and hold up everything. So then we get called in IT to have to clear out that print job and resume the printer queue again.  Those filter errors sometimes don’t make sense at all as to what causes them.  Anyway, so what we would like to have happen is have the queue keep going regardless of a print job with an error.  Although it would be nice to understand those errors and why certain jobs don’t print.  The link you sent explains what might work in order to keep the printer queue going, but still would be nice as to why the errors exist on certain print jobs.
>> 
>> Brian
>> 
>> 
>>> On Jan 19, 2016, at 11:54 AM, Michael Weghorn <m.weghorn at posteo.de> wrote:
>>> 
>>> Hi Brian,
>>> 
>>> you can define what should happen to a print queue in case an error
>>> occurs while printing on this queue.
>>> 
>>> Please see the section "ErrorPolicy" in the documentation at
>>> https://www.cups.org/documentation.php/doc-1.6/ref-printers-conf.html
>>> 
>>> I hope this is what you meant.
>>> 
>>> Best regards,
>>> Michael
>>> 
>>> On 2016-01-19 19:44, Brian Corbin wrote:
>>>> So we have this constant problem where someone will print something and for some reason the print server doesn’t like it and it just pauses the print queue.  This then holds up all print jobs in the queue until it’s removed.  Is there a way to keep this from happening?  Is there some way to setup in the config to force all print jobs to print anyway even if there are errors?  Or is there a way to have cups delete that job or skip it and move on to the others in the queue?  It’s just causing lots of problems for us when a roque print job holds up everything.  If anyone has any advice on this I’m all ears.
>>>> 
>>>> Thanks,
>>>> 
>>>> Brian
>>>> _______________________________________________
>>>> cups mailing list
>>>> cups at cups.org
>>>> https://www.cups.org/mailman/listinfo/cups
>>>> 
>>> _______________________________________________
>>> cups mailing list
>>> cups at cups.org
>>> https://www.cups.org/mailman/listinfo/cups
>> 
>> _______________________________________________
>> cups mailing list
>> cups at cups.org
>> https://www.cups.org/mailman/listinfo/cups
>> 
> _______________________________________________
> cups mailing list
> cups at cups.org
> https://www.cups.org/mailman/listinfo/cups