job 84-error-log-fragment.txt

job-84-error-log-fragment.txt (text/plain), 32.64 KB, created by Derk W te Bokkel on 2012-07-30 19:13:33 UTC

D [30/Jul/2012:14:25:02 -0400] Script header: Content-Type: text/html;charset=utf-8
D [30/Jul/2012:14:25:02 -0400] Script header: 
D [30/Jul/2012:14:25:02 -0400] [Client 16] POST / HTTP/1.1
D [30/Jul/2012:14:25:02 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [30/Jul/2012:14:25:02 -0400] [Client 16] No authentication data provided.
D [30/Jul/2012:14:25:02 -0400] [CGI] Regular expression ".*Clean.*"
D [30/Jul/2012:14:25:02 -0400] [CGI] matches[0].rm_so=0
D [30/Jul/2012:14:25:02 -0400] [CGI] matches[1].rm_so=-1
D [30/Jul/2012:14:25:02 -0400] [CGI] Regular expression ".*PrintSelfTestPage.*"
D [30/Jul/2012:14:25:02 -0400] [CGI] matches[0].rm_so=0
D [30/Jul/2012:14:25:02 -0400] [CGI] matches[1].rm_so=-1
D [30/Jul/2012:14:25:02 -0400] [Client 16] 2.0 Get-Jobs 3
D [30/Jul/2012:14:25:02 -0400] Get-Jobs ipp://localhost:631/printers/DCP-7040
D [30/Jul/2012:14:25:02 -0400] Returning IPP successful-ok for Get-Jobs (ipp://localhost:631/printers/DCP-7040) from localhost
D [30/Jul/2012:14:25:02 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [30/Jul/2012:14:25:02 -0400] [CGI] cgiClearVariables called.
D [30/Jul/2012:14:25:02 -0400] [CGI] cgiSetVariable: ORDER="asc"
D [30/Jul/2012:14:25:02 -0400] [CGI] cgiSetVariable: SECTION="printers"
D [30/Jul/2012:14:25:02 -0400] [CGI] cgiSetVariable: TOTAL="0"
D [30/Jul/2012:14:25:02 -0400] [CGI] cgiSetVariable: PRINTER_NAME="DCP-7040"
D [30/Jul/2012:14:25:02 -0400] [CGI] cgiSetVariable: PRINTER_URI_SUPPORTED="/printers/DCP-7040"
D [30/Jul/2012:14:25:02 -0400] [CGI] cgiSetVariable: THISURL="/printers/DCP-7040"
D [30/Jul/2012:14:25:02 -0400] [CGI] cgiSetVariable: SEARCH_DEST="DCP-7040"
D [30/Jul/2012:14:25:02 -0400] [Client 16] HTTP_WAITING Closing on EOF
D [30/Jul/2012:14:25:02 -0400] [Client 16] Closing connection.
D [30/Jul/2012:14:25:02 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [30/Jul/2012:14:25:02 -0400] PID 1348 (/usr/libexec/cups/cgi-bin/printers.cgi) exited with no errors.
D [30/Jul/2012:14:25:02 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [30/Jul/2012:14:25:07 -0400] [Client 14] POST /printers/DCP-7040 HTTP/1.1
D [30/Jul/2012:14:25:07 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [30/Jul/2012:14:25:07 -0400] [Client 14] Authorized as root using Basic
D [30/Jul/2012:14:25:07 -0400] [CGI] argv[0] = "/usr/libexec/cups/cgi-bin/printers.cgi"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[0] = "CUPS_CACHEDIR=/var/cache/cups"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[1] = "CUPS_DATADIR=/usr/share/cups"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[2] = "CUPS_DOCROOT=/usr/share/cups/html"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[3] = "CUPS_FONTPATH=/usr/share/cups/fonts"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[4] = "CUPS_REQUESTROOT=/var/spool/cups"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/libexec/cups"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[6] = "CUPS_SERVERROOT=/etc/cups"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[7] = "CUPS_STATEDIR=/var/run/cups"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[8] = "HOME=/var/spool/cups/tmp"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[9] = "PATH=/usr/libexec/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[10] = "SERVER_ADMIN=root@zlink0"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[11] = "SOFTWARE=CUPS/1.6.0"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[12] = "TMPDIR=/var/spool/cups/tmp"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[13] = "USER=root"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[14] = "CUPS_MAX_MESSAGE=2047"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[15] = "CUPS_SERVER=/var/run/cups/cups.sock"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[16] = "CUPS_ENCRYPTION=IfRequested"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[17] = "IPP_PORT=631"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[18] = "AUTH_TYPE=Basic"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[19] = "LANG=en_US.UTF8"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[20] = "REDIRECT_STATUS=1"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[21] = "GATEWAY_INTERFACE=CGI/1.1"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[22] = "SERVER_NAME=localhost"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[23] = "SERVER_PORT=631"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[24] = "REMOTE_ADDR=127.0.0.1"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[25] = "REMOTE_HOST=localhost"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[26] = "SCRIPT_NAME=/printers/DCP-7040"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[27] = "SCRIPT_FILENAME=/usr/share/cups/html/printers/DCP-7040"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[28] = "PATH_INFO=/DCP-7040"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[29] = "REMOTE_USER=root"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[30] = "SERVER_PROTOCOL=HTTP/1.1"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[31] = "HTTP_COOKIE=org.cups.sid=d73ac0e6f5d3dea389ce8377c6847d24"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[32] = "HTTP_USER_AGENT=Mozilla/5.0 (X11; Linux x86_64; rv:14.0) Gecko/20100101 Firefox/14.0.1"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[33] = "HTTP_REFERER=http://localhost:631/printers/DCP-7040"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[34] = "REQUEST_METHOD=POST"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[35] = "CONTENT_LENGTH=69"
D [30/Jul/2012:14:25:07 -0400] [CGI] envp[36] = "CONTENT_TYPE=application/x-www-form-urlencoded"
D [30/Jul/2012:14:25:07 -0400] [CGI] Started /usr/libexec/cups/cgi-bin/printers.cgi (PID 1350)
I [30/Jul/2012:14:25:07 -0400] [Client 14] Started "/usr/libexec/cups/cgi-bin/printers.cgi" (pid=1350)
D [30/Jul/2012:14:25:07 -0400] [Client 14] file=16
D [30/Jul/2012:14:25:07 -0400] [CGI] org.cups.sid cookie is "d73ac0e6f5d3dea389ce8377c6847d24"
D [30/Jul/2012:14:25:07 -0400] [CGI] cgiSetVariable: org.cups.sid="d73ac0e6f5d3dea389ce8377c6847d24"
D [30/Jul/2012:14:25:07 -0400] [CGI] cgiSetVariable: OP="print-self-test-page"
D [30/Jul/2012:14:25:07 -0400] [CGI] cgiSetVariable: SECTION="printers"
D [30/Jul/2012:14:25:07 -0400] [CGI] cgiSetVariable: REFRESH_PAGE=""
D [30/Jul/2012:14:25:07 -0400] [CGI] cgiSetVariable: PRINTER_NAME="DCP-7040"
D [30/Jul/2012:14:25:07 -0400] [Client 15] Accepted from localhost (Domain)
D [30/Jul/2012:14:25:07 -0400] [Client 15] POST /printers/DCP-7040 HTTP/1.1
D [30/Jul/2012:14:25:07 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [30/Jul/2012:14:25:07 -0400] [Client 15] No authentication data provided.
D [30/Jul/2012:14:25:07 -0400] [Client 15] 2.0 Create-Job 1
D [30/Jul/2012:14:25:07 -0400] Create-Job ipp://localhost:631/printers/DCP-7040
D [30/Jul/2012:14:25:07 -0400] cupsdMarkDirty(---J-)
D [30/Jul/2012:14:25:07 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients"
D [30/Jul/2012:14:25:07 -0400] add_job: requesting-user-name="root"
D [30/Jul/2012:14:25:07 -0400] Adding default job-sheets values "none,none"...
I [30/Jul/2012:14:25:07 -0400] [Job 84] Adding start banner page "none".
D [30/Jul/2012:14:25:07 -0400] Discarding unused job-created event...
I [30/Jul/2012:14:25:07 -0400] [Job 84] Queued on "DCP-7040" by "root".
D [30/Jul/2012:14:25:07 -0400] Returning IPP successful-ok for Create-Job (ipp://localhost:631/printers/DCP-7040) from localhost
D [30/Jul/2012:14:25:07 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [30/Jul/2012:14:25:07 -0400] [Client 15] POST /printers/DCP-7040 HTTP/1.1
D [30/Jul/2012:14:25:07 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [30/Jul/2012:14:25:07 -0400] [Client 15] No authentication data provided.
D [30/Jul/2012:14:25:07 -0400] [Client 15] 2.0 Send-Document 2
D [30/Jul/2012:14:25:07 -0400] Send-Document ipp://localhost:631/printers/DCP-7040
D [30/Jul/2012:14:25:07 -0400] cupsdIsAuthorized: requesting-user-name="root"
D [30/Jul/2012:14:25:07 -0400] cupsdMarkDirty(---J-)
D [30/Jul/2012:14:25:07 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
I [30/Jul/2012:14:25:07 -0400] [Job 84] File of type application/vnd.cups-command queued by "root".
I [30/Jul/2012:14:25:07 -0400] [Job 84] Adding end banner page "none".
D [30/Jul/2012:14:25:07 -0400] cupsdMarkDirty(---J-)
D [30/Jul/2012:14:25:07 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [30/Jul/2012:14:25:07 -0400] [Job 84] time-at-processing=1343672707
D [30/Jul/2012:14:25:07 -0400] cupsdMarkDirty(---J-)
D [30/Jul/2012:14:25:07 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [30/Jul/2012:14:25:07 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [30/Jul/2012:14:25:07 -0400] Discarding unused printer-state-changed event...
D [30/Jul/2012:14:25:07 -0400] [Job 84] job-sheets=none,none
D [30/Jul/2012:14:25:07 -0400] [Job 84] argv[0]="DCP-7040"
D [30/Jul/2012:14:25:07 -0400] [Job 84] argv[1]="84"
D [30/Jul/2012:14:25:07 -0400] [Job 84] argv[2]="root"
D [30/Jul/2012:14:25:07 -0400] [Job 84] argv[3]="Print Self-Test Page"
D [30/Jul/2012:14:25:07 -0400] [Job 84] argv[4]="1"
D [30/Jul/2012:14:25:07 -0400] [Job 84] argv[5]="job-uuid=urn:uuid:71aabdbb-78b8-3490-6e49-de97e58e804e job-originating-host-name=localhost time-at-creation=1343672707 time-at-processing=1343672707"
D [30/Jul/2012:14:25:07 -0400] [Job 84] argv[6]="/var/spool/cups/d00084-001"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[2]="CUPS_DOCROOT=/usr/share/cups/html"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[5]="CUPS_SERVERBIN=/usr/libexec/cups"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[7]="CUPS_STATEDIR=/var/run/cups"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[8]="HOME=/var/spool/cups/tmp"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[9]="PATH=/usr/libexec/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[10]="SERVER_ADMIN=root@zlink0"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[11]="SOFTWARE=CUPS/1.6.0"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[13]="USER=root"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[14]="CUPS_MAX_MESSAGE=2047"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[15]="CUPS_SERVER=/var/run/cups/cups.sock"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[16]="CUPS_ENCRYPTION=IfRequested"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[17]="IPP_PORT=631"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[18]="CHARSET=utf-8"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[19]="LANG=en_US.UTF-8"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[20]="PPD=/etc/cups/ppd/DCP-7040.ppd"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[21]="RIP_MAX_CACHE=128m"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[22]="CONTENT_TYPE=application/vnd.cups-command"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[23]="DEVICE_URI=lpd://192.168.3.4/lp1"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[24]="PRINTER_INFO=dcp-7040 (dcp-7020 driver)"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[25]="PRINTER_LOCATION=second floor den"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[26]="PRINTER=DCP-7040"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[27]="PRINTER_STATE_REASONS=none"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[28]="CUPS_FILETYPE=document"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[29]="FINAL_CONTENT_TYPE=application/postscript"
D [30/Jul/2012:14:25:07 -0400] [Job 84] envp[30]="AUTH_I****"
I [30/Jul/2012:14:25:07 -0400] [Job 84] Started filter /usr/libexec/cups/filter/commandtops (PID 1351)
I [30/Jul/2012:14:25:07 -0400] [Job 84] Started backend /usr/libexec/cups/backend/lpd (PID 1352)
D [30/Jul/2012:14:25:07 -0400] Discarding unused job-state-changed event...
D [30/Jul/2012:14:25:07 -0400] Returning IPP successful-ok for Send-Document (ipp://localhost:631/printers/DCP-7040) from localhost
D [30/Jul/2012:14:25:07 -0400] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients and dirty files"
D [30/Jul/2012:14:25:07 -0400] PID 1350 (/usr/libexec/cups/cgi-bin/printers.cgi) exited with no errors.
D [30/Jul/2012:14:25:07 -0400] [Client 15] HTTP_WAITING Closing on EOF
D [30/Jul/2012:14:25:07 -0400] [Client 15] Closing connection.
D [30/Jul/2012:14:25:07 -0400] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [30/Jul/2012:14:25:07 -0400] [CGI] cgiSetVariable: refresh_page="5;URL=/printers/DCP-7040"
D [30/Jul/2012:14:25:07 -0400] [CGI] cgiSetVariable: TITLE="Print Self-Test Page"
D [30/Jul/2012:14:25:07 -0400] [CGI] cgiSetVariable: SERVER_NAME="localhost"
D [30/Jul/2012:14:25:07 -0400] [CGI] cgiSetVariable: REMOTE_USER="root"
D [30/Jul/2012:14:25:07 -0400] [CGI] cgiSetVariable: CUPS_VERSION="CUPS v1.6.0"
D [30/Jul/2012:14:25:07 -0400] Script header: Content-Type: text/html;charset=utf-8
D [30/Jul/2012:14:25:07 -0400] Script header: 
D [30/Jul/2012:14:25:07 -0400] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [30/Jul/2012:14:25:07 -0400] [Job 84] PID 1351 (/usr/libexec/cups/filter/commandtops) exited with no errors.
D [30/Jul/2012:14:25:07 -0400] [Job 84] STATE: +connecting-to-device
D [30/Jul/2012:14:25:07 -0400] cupsdMarkDirty(---J-)
D [30/Jul/2012:14:25:07 -0400] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
D [30/Jul/2012:14:25:07 -0400] Discarding unused printer-state-changed event...
D [30/Jul/2012:14:25:07 -0400] [Job 84] Looking up "192.168.3.4"...
D [30/Jul/2012:14:25:07 -0400] [Job 84] backendWaitLoop(snmp_fd=5, addr=0x7f5d382d3d58, side_cb=0x7f5d378e2030)
I [30/Jul/2012:14:25:07 -0400] [Job 84] Copying print data.
D [30/Jul/2012:14:25:07 -0400] cupsdMarkDirty(---J-)
D [30/Jul/2012:14:25:07 -0400] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [30/Jul/2012:14:25:07 -0400] [Job 84] Set job-printer-state-message to "Copying print data.", current level=INFO
D [30/Jul/2012:14:25:07 -0400] Discarding unused job-progress event...
D [30/Jul/2012:14:25:07 -0400] Discarding unused printer-state-changed event...
D [30/Jul/2012:14:25:07 -0400] [Job 84] backendRunLoop(print_fd=-1, device_fd=6, snmp_fd=5, addr=0x7f5d382d3d58, use_bc=0, side_cb=0x7f5d378e2030)
D [30/Jul/2012:14:25:07 -0400] [Job 84] Connecting to 192.168.3.4:515 for printer lp1
I [30/Jul/2012:14:25:07 -0400] [Job 84] Connecting to printer.
D [30/Jul/2012:14:25:07 -0400] cupsdMarkDirty(---J-)
D [30/Jul/2012:14:25:07 -0400] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [30/Jul/2012:14:25:07 -0400] [Job 84] Set job-printer-state-message to "Connecting to printer.", current level=INFO
D [30/Jul/2012:14:25:07 -0400] Discarding unused job-progress event...
D [30/Jul/2012:14:25:07 -0400] Discarding unused printer-state-changed event...
D [30/Jul/2012:14:25:07 -0400] [Job 84] STATE: -connecting-to-device
D [30/Jul/2012:14:25:07 -0400] cupsdMarkDirty(---J-)
D [30/Jul/2012:14:25:07 -0400] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Dirty files"
D [30/Jul/2012:14:25:07 -0400] Discarding unused printer-state-changed event...
I [30/Jul/2012:14:25:07 -0400] [Job 84] Connected to printer.
D [30/Jul/2012:14:25:07 -0400] cupsdMarkDirty(---J-)
D [30/Jul/2012:14:25:07 -0400] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [30/Jul/2012:14:25:07 -0400] [Job 84] Set job-printer-state-message to "Connected to printer.", current level=INFO
D [30/Jul/2012:14:25:07 -0400] Discarding unused job-progress event...
D [30/Jul/2012:14:25:07 -0400] Discarding unused printer-state-changed event...
D [30/Jul/2012:14:25:07 -0400] [Job 84] Connected to 192.168.3.4:515 (local port 1023)...
D [30/Jul/2012:14:25:11 -0400] [Job 84] prtGeneralCurrentLocalization type is 0, expected 2!
D [30/Jul/2012:14:25:11 -0400] [Job 84] lpd_command 02 lp1
D [30/Jul/2012:14:25:11 -0400] [Job 84] Sending command string (5 bytes)...
D [30/Jul/2012:14:25:11 -0400] [Job 84] Reading command status...
D [30/Jul/2012:14:25:11 -0400] [Job 84] lpd_command returning 0
D [30/Jul/2012:14:25:11 -0400] [Job 84] Control file is:
D [30/Jul/2012:14:25:11 -0400] [Job 84] Hzlink0.zapville.org
D [30/Jul/2012:14:25:11 -0400] [Job 84] Proot
D [30/Jul/2012:14:25:11 -0400] [Job 84] JPrint Self_Test Page
D [30/Jul/2012:14:25:11 -0400] [Job 84] ldfA352zlink0.zapville
D [30/Jul/2012:14:25:11 -0400] [Job 84] UdfA352zlink0.zapville
D [30/Jul/2012:14:25:11 -0400] [Job 84] NPrint Self_Test Page
D [30/Jul/2012:14:25:11 -0400] [Job 84] lpd_command 02 117 cfA352zlink0.zapville
D [30/Jul/2012:14:25:11 -0400] [Job 84] Sending command string (27 bytes)...
D [30/Jul/2012:14:25:11 -0400] [Job 84] Reading command status...
D [30/Jul/2012:14:25:11 -0400] [Job 84] lpd_command returning 0
D [30/Jul/2012:14:25:11 -0400] [Job 84] Sending control file (117 bytes)
I [30/Jul/2012:14:25:11 -0400] [Job 84] Control file sent successfully.
D [30/Jul/2012:14:25:11 -0400] cupsdMarkDirty(---J-)
D [30/Jul/2012:14:25:11 -0400] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [30/Jul/2012:14:25:11 -0400] [Job 84] Set job-printer-state-message to "Control file sent successfully.", current level=INFO
D [30/Jul/2012:14:25:11 -0400] Discarding unused job-progress event...
D [30/Jul/2012:14:25:11 -0400] Discarding unused printer-state-changed event...
D [30/Jul/2012:14:25:11 -0400] [Job 84] lpd_command 03 656 dfA352zlink0.zapville
D [30/Jul/2012:14:25:11 -0400] [Job 84] Sending command string (27 bytes)...
D [30/Jul/2012:14:25:11 -0400] [Job 84] Reading command status...
D [30/Jul/2012:14:25:11 -0400] [Job 84] lpd_command returning 0
D [30/Jul/2012:14:25:11 -0400] [Job 84] Sending data file (656 bytes)
I [30/Jul/2012:14:25:11 -0400] [Job 84] Spooling job, 0% complete.
D [30/Jul/2012:14:25:11 -0400] cupsdMarkDirty(---J-)
D [30/Jul/2012:14:25:11 -0400] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [30/Jul/2012:14:25:11 -0400] [Job 84] Set job-printer-state-message to "Spooling job, 0% complete.", current level=INFO
D [30/Jul/2012:14:25:11 -0400] Discarding unused job-progress event...
D [30/Jul/2012:14:25:11 -0400] Discarding unused printer-state-changed event...
I [30/Jul/2012:14:25:11 -0400] [Job 84] Data file sent successfully.
D [30/Jul/2012:14:25:11 -0400] cupsdMarkDirty(---J-)
D [30/Jul/2012:14:25:11 -0400] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [30/Jul/2012:14:25:11 -0400] [Job 84] Set job-printer-state-message to "Data file sent successfully.", current level=INFO
D [30/Jul/2012:14:25:11 -0400] Discarding unused job-progress event...
D [30/Jul/2012:14:25:11 -0400] Discarding unused printer-state-changed event...
D [30/Jul/2012:14:25:11 -0400] [Job 84] PID 1352 (/usr/libexec/cups/backend/lpd) exited with no errors.
D [30/Jul/2012:14:25:11 -0400] [Job 84] time-at-completed=1343672711
D [30/Jul/2012:14:25:11 -0400] Discarding unused job-completed event...
I [30/Jul/2012:14:25:11 -0400] [Job 84] Job completed.
D [30/Jul/2012:14:25:11 -0400] cupsdMarkDirty(---J-)
D [30/Jul/2012:14:25:11 -0400] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [30/Jul/2012:14:25:11 -0400] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [30/Jul/2012:14:25:11 -0400] Discarding unused printer-state-changed event...
D [30/Jul/2012:14:25:11 -0400] cupsdMarkDirty(---J-)
D [30/Jul/2012:14:25:11 -0400] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [30/Jul/2012:14:25:12 -0400] [Client 14] GET /printers/DCP-7040 HTTP/1.1
D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Printing jobs and dirty files"
D [30/Jul/2012:14:25:12 -0400] [Client 14] Authorized as root using Basic
D [30/Jul/2012:14:25:12 -0400] [CGI] argv[0] = "/usr/libexec/cups/cgi-bin/printers.cgi"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[0] = "CUPS_CACHEDIR=/var/cache/cups"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[1] = "CUPS_DATADIR=/usr/share/cups"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[2] = "CUPS_DOCROOT=/usr/share/cups/html"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[3] = "CUPS_FONTPATH=/usr/share/cups/fonts"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[4] = "CUPS_REQUESTROOT=/var/spool/cups"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/libexec/cups"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[6] = "CUPS_SERVERROOT=/etc/cups"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[7] = "CUPS_STATEDIR=/var/run/cups"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[8] = "HOME=/var/spool/cups/tmp"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[9] = "PATH=/usr/libexec/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[10] = "SERVER_ADMIN=root@zlink0"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[11] = "SOFTWARE=CUPS/1.6.0"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[12] = "TMPDIR=/var/spool/cups/tmp"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[13] = "USER=root"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[14] = "CUPS_MAX_MESSAGE=2047"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[15] = "CUPS_SERVER=/var/run/cups/cups.sock"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[16] = "CUPS_ENCRYPTION=IfRequested"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[17] = "IPP_PORT=631"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[18] = "AUTH_TYPE=Basic"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[19] = "LANG=en_US.UTF8"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[20] = "REDIRECT_STATUS=1"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[21] = "GATEWAY_INTERFACE=CGI/1.1"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[22] = "SERVER_NAME=localhost"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[23] = "SERVER_PORT=631"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[24] = "REMOTE_ADDR=127.0.0.1"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[25] = "REMOTE_HOST=localhost"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[26] = "SCRIPT_NAME=/printers/DCP-7040"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[27] = "SCRIPT_FILENAME=/usr/share/cups/html/printers/DCP-7040"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[28] = "PATH_INFO=/DCP-7040"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[29] = "REMOTE_USER=root"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[30] = "SERVER_PROTOCOL=HTTP/1.1"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[31] = "HTTP_COOKIE=org.cups.sid=d73ac0e6f5d3dea389ce8377c6847d24"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[32] = "HTTP_USER_AGENT=Mozilla/5.0 (X11; Linux x86_64; rv:14.0) Gecko/20100101 Firefox/14.0.1"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[33] = "REQUEST_METHOD=GET"
D [30/Jul/2012:14:25:12 -0400] [CGI] envp[34] = "QUERY_STRING="
D [30/Jul/2012:14:25:12 -0400] [CGI] Started /usr/libexec/cups/cgi-bin/printers.cgi (PID 1357)
I [30/Jul/2012:14:25:12 -0400] [Client 14] Started "/usr/libexec/cups/cgi-bin/printers.cgi" (pid=1357)
D [30/Jul/2012:14:25:12 -0400] [Client 14] file=15
D [30/Jul/2012:14:25:12 -0400] [Job 84] Unloading...
D [30/Jul/2012:14:25:12 -0400] [CGI] org.cups.sid cookie is "d73ac0e6f5d3dea389ce8377c6847d24"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: SECTION="printers"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: REFRESH_PAGE=""
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: PRINTER_NAME="DCP-7040"
D [30/Jul/2012:14:25:12 -0400] [Client 16] Accepted from localhost (Domain)
D [30/Jul/2012:14:25:12 -0400] [Client 16] POST / HTTP/1.1
D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [30/Jul/2012:14:25:12 -0400] [Client 16] No authentication data provided.
D [30/Jul/2012:14:25:12 -0400] [Client 16] 2.0 CUPS-Get-Default 1
D [30/Jul/2012:14:25:12 -0400] CUPS-Get-Default
D [30/Jul/2012:14:25:12 -0400] CUPS-Get-Default client-error-not-found: No default printer.
D [30/Jul/2012:14:25:12 -0400] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [30/Jul/2012:14:25:12 -0400] [CGI] show_printer(http=0x7fc441ae03c0, printer="DCP-7040")
D [30/Jul/2012:14:25:12 -0400] [Client 16] POST / HTTP/1.1
D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [30/Jul/2012:14:25:12 -0400] [Client 16] No authentication data provided.
D [30/Jul/2012:14:25:12 -0400] [Client 16] 2.0 Get-Printer-Attributes 2
D [30/Jul/2012:14:25:12 -0400] Get-Printer-Attributes ipp://localhost/printers/DCP-7040
D [30/Jul/2012:14:25:12 -0400] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/DCP-7040) from localhost
D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: SERVER_NAME="localhost"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: REMOTE_USER="root"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: CUPS_VERSION="CUPS v1.6.0"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: SERVER_NAME="localhost"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: REMOTE_USER="root"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: CUPS_VERSION="CUPS v1.6.0"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetArray: printer_is_accepting_jobs[0]="1"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetArray: printer_is_shared[0]="0"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetArray: printer_state[0]="3"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetArray: admin_uri[0]="/admin/"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetArray: printer_uri_supported[0]="/printers/DCP-7040"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetArray: printer_name[0]="DCP-7040"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetArray: printer_location[0]="second floor den"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetArray: printer_info[0]="dcp-7040 (dcp-7020 driver)"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetArray: job_sheets_default[0]="none, none"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetArray: device_uri[0]="lpd://192.168.3.4/lp1"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetArray: color_supported[0]="0"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetArray: printer_make_and_model[0]="Brother DCP-7020 Foomatic/hl1250 (recommended)"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetArray: media_default[0]="na_letter_8.5x11in"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetArray: sides_supported[0]="one-sided"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetArray: sides_default[0]="one-sided"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetArray: printer_commands[0]="AutoConfigure, Clean, PrintSelfTestPage"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetArray: server_is_sharing_printers[0]="0"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: TITLE="DCP-7040"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: SERVER_NAME="localhost"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: REMOTE_USER="root"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: CUPS_VERSION="CUPS v1.6.0"
D [30/Jul/2012:14:25:12 -0400] Script header: Content-Type: text/html;charset=utf-8
D [30/Jul/2012:14:25:12 -0400] Script header: 
D [30/Jul/2012:14:25:12 -0400] [CGI] Regular expression ".*Clean.*"
D [30/Jul/2012:14:25:12 -0400] [CGI] matches[0].rm_so=0
D [30/Jul/2012:14:25:12 -0400] [CGI] matches[1].rm_so=-1
D [30/Jul/2012:14:25:12 -0400] [CGI] Regular expression ".*PrintSelfTestPage.*"
D [30/Jul/2012:14:25:12 -0400] [CGI] matches[0].rm_so=0
D [30/Jul/2012:14:25:12 -0400] [CGI] matches[1].rm_so=-1
D [30/Jul/2012:14:25:12 -0400] [Client 16] POST / HTTP/1.1
D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [30/Jul/2012:14:25:12 -0400] [Client 16] No authentication data provided.
D [30/Jul/2012:14:25:12 -0400] [Client 16] 2.0 Get-Jobs 3
D [30/Jul/2012:14:25:12 -0400] Get-Jobs ipp://localhost:631/printers/DCP-7040
D [30/Jul/2012:14:25:12 -0400] Returning IPP successful-ok for Get-Jobs (ipp://localhost:631/printers/DCP-7040) from localhost
D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiClearVariables called.
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: ORDER="asc"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: SECTION="printers"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: TOTAL="0"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: PRINTER_NAME="DCP-7040"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: PRINTER_URI_SUPPORTED="/printers/DCP-7040"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: THISURL="/printers/DCP-7040"
D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: SEARCH_DEST="DCP-7040"
D [30/Jul/2012:14:25:12 -0400] [Client 16] HTTP_WAITING Closing on EOF
D [30/Jul/2012:14:25:12 -0400] [Client 16] Closing connection.
D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [30/Jul/2012:14:25:12 -0400] PID 1357 (/usr/libexec/cups/cgi-bin/printers.cgi) exited with no errors.
D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [30/Jul/2012:14:25:12 -0400] [Client 14] GET /cups.css HTTP/1.1
D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [30/Jul/2012:14:25:12 -0400] [Client 14] Authorized as root using Basic
D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [30/Jul/2012:14:25:12 -0400] [Client 15] Accepted from localhost:631 (IPv4)
D [30/Jul/2012:14:25:12 -0400] [Client 16] Accepted from localhost:631 (IPv4)
D [30/Jul/2012:14:25:12 -0400] [Client 15] GET /images/left.gif HTTP/1.1
D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [30/Jul/2012:14:25:12 -0400] [Client 15] Authorized as root using Basic
D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [30/Jul/2012:14:25:12 -0400] [Client 16] GET /images/right.gif HTTP/1.1
D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [30/Jul/2012:14:25:12 -0400] [Client 16] Authorized as root using Basic
D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [30/Jul/2012:14:25:12 -0400] [Client 14] GET /images/unsel.gif HTTP/1.1
D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [30/Jul/2012:14:25:12 -0400] [Client 14] Authorized as root using Basic
D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [30/Jul/2012:14:25:12 -0400] [Client 15] GET /images/sel.gif HTTP/1.1
D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [30/Jul/2012:14:25:12 -0400] [Client 15] Authorized as root using Basic
D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
I [30/Jul/2012:14:25:38 -0400] Saving job.cache...
D [30/Jul/2012:14:25:38 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Dirty files"
D [30/Jul/2012:14:25:43 -0400] [Client 16] HTTP_WAITING Closing on EOF
D [30/Jul/2012:14:25:43 -0400] [Client 16] Closing connection.
D [30/Jul/2012:14:25:43 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [30/Jul/2012:14:25:43 -0400] [Client 15] HTTP_WAITING Closing on EOF
D [30/Jul/2012:14:25:43 -0400] [Client 15] Closing connection.
D [30/Jul/2012:14:25:43 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [30/Jul/2012:14:25:43 -0400] [Client 14] HTTP_WAITING Closing on EOF
D [30/Jul/2012:14:25:43 -0400] [Client 14] Closing connection.
D [30/Jul/2012:14:25:43 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [30/Jul/2012:14:30:04 -0400] [Client 14] Accepted from localhost:631 (IPv4)
D [30/Jul/2012:14:30:04 -0400] Report: clients=1
D [30/Jul/2012:14:30:04 -0400] Report: jobs=15
D [30/Jul/2012:14:30:04 -0400] Report: jobs-active=0
D [30/Jul/2012:14:30:04 -0400] Report: printers=1
D [30/Jul/2012:14:30:04 -0400] Report: stringpool-string-count=4645
D [30/Jul/2012:14:30:04 -0400] Report: stringpool-alloc-bytes=8712
D [30/Jul/2012:14:30:04 -0400] Report: stringpool-total-bytes=79600
D [30/Jul/2012:14:30:04 -0400] [Client 14] GET /admin HTTP/1.1
D [30/Jul/2012:14:30:04 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"