D [17/Oct/2023:09:51:36 +1100] [Job 133] 3 filters for job:
D [17/Oct/2023:09:51:36 +1100] [Job 133] texttopdf (text/plain to application/pdf, cost 32)
D [17/Oct/2023:09:51:36 +1100] [Job 133] pdftopdf (application/pdf to application/vnd.cups-pdf, cost 66)
D [17/Oct/2023:09:51:36 +1100] [Job 133] - (application/vnd.cups-pdf to printer/PDFPrinter, cost 0)
D [17/Oct/2023:09:51:36 +1100] [Job 133] job-sheets=none,none
D [17/Oct/2023:09:51:36 +1100] [Job 133] argv[0]="PDFPrinter"
D [17/Oct/2023:09:51:36 +1100] [Job 133] argv[1]="133"
D [17/Oct/2023:09:51:36 +1100] [Job 133] argv[2]="student"
D [17/Oct/2023:09:51:36 +1100] [Job 133] argv[3]="cups_test.txt"
D [17/Oct/2023:09:51:36 +1100] [Job 133] argv[4]="1"
D [17/Oct/2023:09:51:36 +1100] [Job 133] argv[5]="finishings=3 number-up=1 print-color-mode=monochrome job-uuid=urn:uuid:1474ce18-1425-3a42-4029-15022960e597 job-originating-host-name={rule58 IP} date-time-at-creation= date-time-at-processing= time-at-creation=1697496696 time-at-processing=1697496696 document-name-supplied=cups_test.txt"
D [17/Oct/2023:09:51:36 +1100] [Job 133] argv[6]="/var/spool/cups/d00133-001"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[1]="CUPS_DATADIR=/usr/local/share/cups"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[2]="CUPS_DOCROOT=/usr/local/share/doc/cups"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[3]="CUPS_REQUESTROOT=/var/spool/cups"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[4]="CUPS_SERVERBIN=/usr/local/libexec/cups"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[5]="CUPS_SERVERROOT=/usr/local/etc/cups"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[6]="CUPS_STATEDIR=/var/run/cups"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[7]="HOME=/var/spool/cups/tmp"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[8]="PATH=/usr/local/libexec/cups/filter:/usr/local/bin:/usr/local/sbin:/bin:/usr/bin"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[9]="SERVER_ADMIN=root@rule58"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[10]="SOFTWARE=CUPS/2.4.6"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[11]="TMPDIR=/var/spool/cups/tmp"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[12]="USER=root"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[13]="CUPS_MAX_MESSAGE=2047"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[14]="CUPS_SERVER=/var/run/cups/cups.sock"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[15]="CUPS_ENCRYPTION=IfRequested"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[16]="IPP_PORT=631"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[17]="CHARSET=utf-8"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[18]="LANG=en_US.UTF-8"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[19]="PPD=/usr/local/etc/cups/ppd/PDFPrinter.ppd"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[20]="CONTENT_TYPE=text/plain"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[21]="DEVICE_URI=pdf:/"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[22]="PRINTER_INFO="
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[23]="PRINTER_LOCATION="
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[24]="PRINTER=PDFPrinter"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[25]="PRINTER_STATE_REASONS=none"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[26]="CUPS_FILETYPE=document"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[27]="FINAL_CONTENT_TYPE=application/vnd.cups-pdf"
D [17/Oct/2023:09:51:36 +1100] [Job 133] envp[28]="AUTH_I****"
I [17/Oct/2023:09:51:36 +1100] [Job 133] Started filter /usr/local/libexec/cups/filter/texttopdf (PID 989)
I [17/Oct/2023:09:51:36 +1100] [Job 133] Started filter /usr/local/libexec/cups/filter/pdftopdf (PID 990)
I [17/Oct/2023:09:51:36 +1100] [Job 133] Started backend /usr/local/libexec/cups/backend/pdf (PID 991)
D [17/Oct/2023:09:51:36 +1100] Discarding unused job-state-changed event...
D [17/Oct/2023:09:51:36 +1100] [Client 517] Returning IPP successful-ok for Send-Document (ipp://localhost:631/printers/PDFPrinter) from {rule58 IP}.
D [17/Oct/2023:09:51:36 +1100] [Client 517] Content-Length: 180
D [17/Oct/2023:09:51:36 +1100] [Client 517] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [17/Oct/2023:09:51:36 +1100] [Client 517] con->http=0x806482800
D [17/Oct/2023:09:51:36 +1100] [Client 517] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=180, response=0x8064f75a0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [17/Oct/2023:09:51:36 +1100] [Client 517] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [17/Oct/2023:09:51:36 +1100] [Client 517] bytes=0, http_state=0, data_remaining=180
D [17/Oct/2023:09:51:36 +1100] [Client 517] Flushing write buffer.
D [17/Oct/2023:09:51:36 +1100] [Client 517] New state is HTTP_STATE_WAITING
D [17/Oct/2023:09:51:36 +1100] [Client 517] Waiting for request.
D [17/Oct/2023:09:51:36 +1100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients and dirty files"
D [17/Oct/2023:09:51:36 +1100] [Job 133] backend=/usr/local/libexec/cups/backend/pdf
D [17/Oct/2023:09:51:36 +1100] cupsdMarkDirty(---J-)
D [17/Oct/2023:09:51:36 +1100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [17/Oct/2023:09:51:36 +1100] cupsdMarkDirty(---J-)
D [17/Oct/2023:09:51:36 +1100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [17/Oct/2023:09:51:36 +1100] [Job 133] Set job-printer-state-message to "backend=/usr/local/libexec/cups/backend/pdf", current level=INFO
D [17/Oct/2023:09:51:36 +1100] [Job 133] jobid=133
D [17/Oct/2023:09:51:36 +1100] cupsdMarkDirty(---J-)
D [17/Oct/2023:09:51:36 +1100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [17/Oct/2023:09:51:36 +1100] [Job 133] Set job-printer-state-message to "jobid=133", current level=INFO
D [17/Oct/2023:09:51:36 +1100] [Job 133] cupsuser=student
D [17/Oct/2023:09:51:36 +1100] cupsdMarkDirty(---J-)
D [17/Oct/2023:09:51:36 +1100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [17/Oct/2023:09:51:36 +1100] [Job 133] Set job-printer-state-message to "cupsuser=student", current level=INFO
D [17/Oct/2023:09:51:36 +1100] [Job 133] jobtitle=cups_test.txt
D [17/Oct/2023:09:51:36 +1100] cupsdMarkDirty(---J-)
D [17/Oct/2023:09:51:36 +1100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [17/Oct/2023:09:51:36 +1100] [Job 133] Set job-printer-state-message to "jobtitle=cups_test.txt", current level=INFO
D [17/Oct/2023:09:51:36 +1100] [Job 133] jobcopies=1
D [17/Oct/2023:09:51:36 +1100] cupsdMarkDirty(---J-)
D [17/Oct/2023:09:51:36 +1100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [17/Oct/2023:09:51:36 +1100] [Job 133] Set job-printer-state-message to "jobcopies=1", current level=INFO
D [17/Oct/2023:09:51:36 +1100] [Job 133] joboptions=finishings=3 number-up=1 print-color-mode=monochrome job-uuid=urn:uuid:1474ce18-1425-3a42-4029-15022960e597 job-originating-host-name={rule58 IP} date-time-at-creation= date-time-at-processing= time-at-creation=1697496696 time-at-processing=1697496696 document-name-supplied=cups_test.txt
D [17/Oct/2023:09:51:36 +1100] cupsdMarkDirty(---J-)
D [17/Oct/2023:09:51:36 +1100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [17/Oct/2023:09:51:36 +1100] [Job 133] Set job-printer-state-message to "joboptions=finishings=3 number-up=1 print-color-mode=monochrome job-uuid=urn:uuid:1474ce18-1425-3a42-4029-15022960e597 job-originating-host-name={rule58 IP} date-time-at-creation= date-time-at-processing= time-at-creation=1697496696 time-at-processing=1697496696 document-name-supplied=cups_test.txt", current level=INFO
D [17/Oct/2023:09:51:36 +1100] [Job 133] jobfile=
D [17/Oct/2023:09:51:36 +1100] cupsdMarkDirty(---J-)
D [17/Oct/2023:09:51:36 +1100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [17/Oct/2023:09:51:36 +1100] [Job 133] Set job-printer-state-message to "jobfile=", current level=INFO
D [17/Oct/2023:09:51:36 +1100] [Job 133] printtime=
D [17/Oct/2023:09:51:36 +1100] cupsdMarkDirty(---J-)
D [17/Oct/2023:09:51:36 +1100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [17/Oct/2023:09:51:36 +1100] [Job 133] Set job-printer-state-message to "printtime=", current level=INFO
X [17/Oct/2023:09:51:36 +1100] [Job 133] This is a \"emergency\" level log message
D [17/Oct/2023:09:51:36 +1100] cupsdMarkDirty(---J-)
D [17/Oct/2023:09:51:36 +1100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [17/Oct/2023:09:51:36 +1100] [Job 133] Set job-printer-state-message to "This is a \"emergency\" level log message", current level=EMERG
A [17/Oct/2023:09:51:36 +1100] [Job 133] This is a \"alert\" level log message
C [17/Oct/2023:09:51:36 +1100] [Job 133] This is a \"critical\" level log message
E [17/Oct/2023:09:51:36 +1100] [Job 133] This is a \"error\" level log message
D [17/Oct/2023:09:51:36 +1100] [Job 133] WARN: This is a \"warn\" level log message
N [17/Oct/2023:09:51:36 +1100] [Job 133] This is a \"notice\" level log message
D [17/Oct/2023:09:51:36 +1100] [Job 133] This is a \"info\" level log message
D [17/Oct/2023:09:51:36 +1100] [Job 133] This is a 2nd \"info\" level log message
D [17/Oct/2023:09:51:36 +1100] [Job 133] This is a 3rd \"info\" level log message
D [17/Oct/2023:09:51:36 +1100] [Job 133] This is a \"debug\" level log message
D [17/Oct/2023:09:51:36 +1100] [Job 133] pdftopdf: Last filter determined by the PPD: -; FINAL_CONTENT_TYPE: application/vnd.cups-pdf => pdftopdf will log pages in page_log.
D [17/Oct/2023:09:51:36 +1100] Discarding unused job-progress event...
D [17/Oct/2023:09:51:36 +1100] Discarding unused printer-state-changed event...
D [17/Oct/2023:09:51:36 +1100] [Job 133] /usr/local/libexec/cups/backend/pdf: line 53: /: Is a directory
D [17/Oct/2023:09:51:36 +1100] [Client 517] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [17/Oct/2023:09:51:36 +1100] [Client 517] Closing connection.
D [17/Oct/2023:09:51:36 +1100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [17/Oct/2023:09:51:36 +1100] [Job 133] Page = 595x842; 18,36 to 577,806
D [17/Oct/2023:09:51:36 +1100] [Job 133] No viable font found
W [17/Oct/2023:09:51:36 +1100] [Job 133] Ignored bad font \"monospace\"
D [17/Oct/2023:09:51:36 +1100] Discarding unused job-progress event...
D [17/Oct/2023:09:51:36 +1100] Discarding unused printer-state-changed event...
D [17/Oct/2023:09:51:36 +1100] [Job 133] No viable font found
W [17/Oct/2023:09:51:36 +1100] [Job 133] Ignored bad font \"monospace\"
D [17/Oct/2023:09:51:36 +1100] [Job 133] No viable font found
W [17/Oct/2023:09:51:36 +1100] [Job 133] Ignored bad font \"ARPLUmingCN\"
E [17/Oct/2023:09:51:36 +1100] [Job 133] No usable font available
D [17/Oct/2023:09:51:36 +1100] Discarding unused job-progress event...
D [17/Oct/2023:09:51:36 +1100] Discarding unused printer-state-changed event...
W [17/Oct/2023:09:51:36 +1100] [Job 133] temp file: file is damaged
D [17/Oct/2023:09:51:36 +1100] Discarding unused job-progress event...
D [17/Oct/2023:09:51:36 +1100] Discarding unused printer-state-changed event...
W [17/Oct/2023:09:51:36 +1100] [Job 133] temp file: can\'t find startxref
D [17/Oct/2023:09:51:36 +1100] Discarding unused job-progress event...
D [17/Oct/2023:09:51:36 +1100] Discarding unused printer-state-changed event...
W [17/Oct/2023:09:51:36 +1100] [Job 133] temp file: Attempting to reconstruct cross-reference table
D [17/Oct/2023:09:51:36 +1100] Discarding unused job-progress event...
D [17/Oct/2023:09:51:36 +1100] Discarding unused printer-state-changed event...
D [17/Oct/2023:09:51:36 +1100] [Job 133] PID 989 (/usr/local/libexec/cups/filter/texttopdf) stopped with status 1.
E [17/Oct/2023:09:51:36 +1100] [Job 133] loadFile failed: temp file: unable to find trailer dictionary while recovering damaged file
D [17/Oct/2023:09:51:36 +1100] Discarding unused job-progress event...
D [17/Oct/2023:09:51:36 +1100] Discarding unused printer-state-changed event...
D [17/Oct/2023:09:51:36 +1100] [Job 133] PID 990 (/usr/local/libexec/cups/filter/pdftopdf) stopped with status 1.
D [17/Oct/2023:09:51:36 +1100] [Job 133] PID 991 (/usr/local/libexec/cups/backend/pdf) exited with no errors.
D [17/Oct/2023:09:51:36 +1100] Discarding unused job-state-changed event...
E [17/Oct/2023:09:51:36 +1100] [Job 133] Job stopped due to filter errors; please consult the /var/log/cups/error_log file for details.
D [17/Oct/2023:09:51:36 +1100] cupsdMarkDirty(---J-)
D [17/Oct/2023:09:51:36 +1100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [17/Oct/2023:09:51:36 +1100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [17/Oct/2023:09:51:36 +1100] Discarding unused printer-state-changed event...
D [17/Oct/2023:09:51:37 +1100] [Job 133] Unloading...
D [17/Oct/2023:09:51:40 +1100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Printing jobs and dirty files"