Hi all,
unable to print from linux box. Earlier it used to work fine.
The print job is sitting in the queue and not going to printer.
Removed queue job and tried again but no luck.
Tried "cupsenable" but ended up with no success.
I tried to print two text files as "root" with "lp " command but no print.
I even tried to restart "cups" daemon and then "cupsenable" and same result.
I am attaching the error log file after trying above steps.
# /etc/init.d/cups status
cupsd (pid 29679) is running...
Below is the error log file . Please help me to solve this.
Thanks in advance!
D [06/Jun/2012:09:51:44 -0400] ProcessIPPRequest: 8 status_code=1
D [06/Jun/2012:09:51:44 -0400] ReadClient: 8 POST / HTTP/1.1
D [06/Jun/2012:09:51:44 -0400] ProcessIPPRequest: 8 status_code=0
D [06/Jun/2012:09:51:44 -0400] AcceptClient: 9 from localhost:631.
D [06/Jun/2012:09:51:44 -0400] CloseClient: 8
D [06/Jun/2012:09:51:44 -0400] ReadClient: 9 POST /printers/usbmpr2045 HTTP/1.1
D [06/Jun/2012:09:51:44 -0400] print_job: auto-typing file...
D [06/Jun/2012:09:51:44 -0400] print_job: request file type is text/plain.
D [06/Jun/2012:09:51:44 -0400] CancelJob: id = 13973
D [06/Jun/2012:09:51:44 -0400] check_quotas: requesting-user-name = 'root'
D [06/Jun/2012:09:51:44 -0400] print_job: requesting-user-name = 'root'
I [06/Jun/2012:09:51:44 -0400] Adding start banner page "none" to job 14473.
I [06/Jun/2012:09:51:44 -0400] Adding end banner page "none" to job 14473.
I [06/Jun/2012:09:51:44 -0400] Job 14473 queued on 'usbmpr2045' by 'root'.
D [06/Jun/2012:09:51:44 -0400] Job 14473 hold_until = 0
D [06/Jun/2012:09:51:44 -0400] StartJob(14473, 0x552abf95e0)
D [06/Jun/2012:09:51:44 -0400] StartJob() id = 14473, file = 0/1
D [06/Jun/2012:09:51:44 -0400] StartJob: Sending job to queue tagged as raw...
D [06/Jun/2012:09:51:44 -0400] job-sheets=none,none
D [06/Jun/2012:09:51:44 -0400] banner_page = 0
D [06/Jun/2012:09:51:44 -0400] StartJob: argv = "usbmpr2045","14473","root","testfile.txt","1","cpi=12 lpi=7 page-bottom=86 page-left=57 page-right=57 page-top=72 scaling=100 wrap","/var/spool/cups/d14473-001"
D [06/Jun/2012:09:51:44 -0400] StartJob: envp[0]="PATH=/usr/lib64/cups/filter:/bin:/usr/bin"
D [06/Jun/2012:09:51:44 -0400] StartJob: envp[1]="SOFTWARE=CUPS/1.1"
D [06/Jun/2012:09:51:44 -0400] StartJob: envp[2]="USER=root"
D [06/Jun/2012:09:51:44 -0400] StartJob: envp[3]="CHARSET=utf-8"
D [06/Jun/2012:09:51:44 -0400] StartJob: envp[4]="LANG=en_SG"
D [06/Jun/2012:09:51:44 -0400] StartJob: envp[5]="PPD=/etc/cups/ppd/usbmpr2045.ppd"
D [06/Jun/2012:09:51:44 -0400] StartJob: envp[6]="CUPS_SERVERROOT=/etc/cups"
D [06/Jun/2012:09:51:44 -0400] StartJob: envp[7]="RIP_MAX_CACHE=8m"
D [06/Jun/2012:09:51:44 -0400] StartJob: envp[8]="TMPDIR=/var/spool/cups/tmp"
D [06/Jun/2012:09:51:44 -0400] StartJob: envp[9]="CONTENT_TYPE=text/plain"
D [06/Jun/2012:09:51:44 -0400] StartJob: envp[10]="DEVICE_URI=lpd://usbmps0001/usbmpr2045"
D [06/Jun/2012:09:51:44 -0400] StartJob: envp[11]="PRINTER=usbmpr2045"
D [06/Jun/2012:09:51:44 -0400] StartJob: envp[12]="CUPS_DATADIR=/usr/share/cups"
D [06/Jun/2012:09:51:44 -0400] StartJob: envp[13]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [06/Jun/2012:09:51:44 -0400] StartJob: envp[14]="CUPS_SERVER=localhost"
D [06/Jun/2012:09:51:44 -0400] StartJob: envp[15]="IPP_PORT=631"
D [06/Jun/2012:09:51:44 -0400] StartJob: statusfds = [ 8 11 ]
D [06/Jun/2012:09:51:44 -0400] StartJob: filterfds[1] = [ 12 -1 ]
D [06/Jun/2012:09:51:44 -0400] StartJob: backend = "/usr/lib64/cups/backend/lpd"
D [06/Jun/2012:09:51:44 -0400] StartJob: filterfds[0] = [ -1 13 ]
D [06/Jun/2012:09:51:44 -0400] start_process("/usr/lib64/cups/backend/lpd", 0x7fbffee800, 0x7fbffed9e0, 12, 13, 11)
I [06/Jun/2012:09:51:44 -0400] Started backend /usr/lib64/cups/backend/lpd (PID 22968) for job 14473.
D [06/Jun/2012:09:51:44 -0400] ProcessIPPRequest: 9 status_code=0
D [06/Jun/2012:09:51:44 -0400] CloseClient: 9
D [06/Jun/2012:09:51:44 -0400] [Job 14473] Connected on ports 515 (local 1023)...
D [06/Jun/2012:09:51:44 -0400] [Job 14473] lpd_command 02 usbmpr2045
D [06/Jun/2012:09:51:44 -0400] [Job 14473] Sending command string (12 bytes)...
D [06/Jun/2012:09:51:44 -0400] [Job 14473] Reading command status...
D [06/Jun/2012:09:51:44 -0400] [Job 14473] lpd_command returning 0
D [06/Jun/2012:09:51:44 -0400] [Job 14473] Control file is:
D [06/Jun/2012:09:51:44 -0400] [Job 14473] Hbloch2
D [06/Jun/2012:09:51:44 -0400] [Job 14473] Proot
D [06/Jun/2012:09:51:44 -0400] [Job 14473] Jtestfile_txt
D [06/Jun/2012:09:51:44 -0400] [Job 14473] ldfA968bloch2
D [06/Jun/2012:09:51:44 -0400] [Job 14473] UdfA968bloch2
D [06/Jun/2012:09:51:44 -0400] [Job 14473] Ntestfile_txt
D [06/Jun/2012:09:51:44 -0400] [Job 14473] lpd_command 02 70 cfA968bloch2
D [06/Jun/2012:09:51:44 -0400] [Job 14473] Sending command string (17 bytes)...
D [06/Jun/2012:09:51:44 -0400] [Job 14473] Reading command status...
D [06/Jun/2012:09:51:44 -0400] [Job 14473] lpd_command returning 0
D [06/Jun/2012:09:51:44 -0400] [Job 14473] lpd_command 03 53 dfA968bloch2
D [06/Jun/2012:09:51:44 -0400] [Job 14473] Sending command string (17 bytes)...
D [06/Jun/2012:09:51:44 -0400] [Job 14473] Reading command status...
D [06/Jun/2012:09:51:44 -0400] [Job 14473] lpd_command returning 0
D [06/Jun/2012:09:51:44 -0400] UpdateJob: job 14473, file 0 is complete.
D [06/Jun/2012:09:51:44 -0400] CancelJob: id = 14473
D [06/Jun/2012:09:51:44 -0400] StopJob: id = 14473, force = 0
D [06/Jun/2012:09:51:44 -0400] StopJob: printer state is 3
D [06/Jun/2012:09:51:46 -0400] ReadClient: 6 POST / HTTP/1.1
D [06/Jun/2012:09:51:47 -0400] ProcessIPPRequest: 6 status_code=0
D [06/Jun/2012:09:51:49 -0400] AcceptClient: 8 from localhost:631.
D [06/Jun/2012:09:51:49 -0400] AcceptClient: 9 from localhost:631.
D [06/Jun/2012:09:51:49 -0400] ReadClient: 9 POST / HTTP/1.1
D [06/Jun/2012:09:51:49 -0400] ProcessIPPRequest: 9 status_code=1
D [06/Jun/2012:09:51:49 -0400] ReadClient: 9 POST / HTTP/1.1
D [06/Jun/2012:09:54:05 -0400] ProcessIPPRequest: 6 status_code=0
D [06/Jun/2012:09:54:10 -0400] AcceptClient: 8 from localhost:631.
D [06/Jun/2012:09:54:10 -0400] ReadClient: 8 POST /printers/ HTTP/1.1
D [06/Jun/2012:09:54:10 -0400] ProcessIPPRequest: 8 status_code=1
D [06/Jun/2012:09:54:10 -0400] CloseClient: 8
D [06/Jun/2012:09:54:11 -0400] ReadClient: 6 POST / HTTP/1.1
D [06/Jun/2012:09:54:41 -0400] ProcessIPPRequest: 6 status_code=0
D [06/Jun/2012:09:54:47 -0400] ReadClient: 6 POST / HTTP/1.1
D [06/Jun/2012:09:54:47 -0400] ProcessIPPRequest: 6 status_code=0
D [06/Jun/2012:09:54:47 -0400] AcceptClient: 8 from localhost:631.
D [06/Jun/2012:09:54:47 -0400] AcceptClient: 9 from localhost:631.
D [06/Jun/2012:09:54:47 -0400] ReadClient: 9 POST / HTTP/1.1
D [06/Jun/2012:09:54:47 -0400] ProcessIPPRequest: 9 status_code=1
D [06/Jun/2012:09:54:47 -0400] ReadClient: 9 POST / HTTP/1.1
D [06/Jun/2012:09:54:47 -0400] ProcessIPPRequest: 9 status_code=1
D [06/Jun/2012:09:54:47 -0400] ReadClient: 9 POST / HTTP/1.1
D [06/Jun/2012:09:54:47 -0400] ProcessIPPRequest: 9 status_code=0
D [06/Jun/2012:09:54:47 -0400] CloseClient: 9
D [06/Jun/2012:09:54:47 -0400] ReadClient: 8 POST / HTTP/1.1
D [06/Jun/2012:09:54:47 -0400] ProcessIPPRequest: 8 status_code=0
D [06/Jun/2012:09:54:47 -0400] ReadClient: 8 POST / HTTP/1.1
D [06/Jun/2012:09:54:47 -0400] ProcessIPPRequest: 8 status_code=0
D [06/Jun/2012:09:54:47 -0400] CloseClient: 8
D [06/Jun/2012:09:54:53 -0400] ReadClient: 6 POST / HTTP/1.1
D [06/Jun/2012:09:54:53 -0400] ProcessIPPRequest: 6 status_code=0
D [06/Jun/2012:09:56:14 -0400] ProcessIPPRequest: 8 status_code=0
D [06/Jun/2012:09:56:14 -0400] AcceptClient: 9 from localhost:631.
D [06/Jun/2012:09:56:14 -0400] CloseClient: 8
D [06/Jun/2012:09:56:14 -0400] ReadClient: 9 POST /printers/usbmpr2051 HTTP/1.1
D [06/Jun/2012:09:56:14 -0400] print_job: auto-typing file...
D [06/Jun/2012:09:56:14 -0400] print_job: request file type is text/plain.
D [06/Jun/2012:09:56:14 -0400] CancelJob: id = 13974
D [06/Jun/2012:09:56:14 -0400] check_quotas: requesting-user-name = 'root'
D [06/Jun/2012:09:56:14 -0400] print_job: requesting-user-name = 'root'
I [06/Jun/2012:09:56:14 -0400] Adding start banner page "none" to job 14474.
I [06/Jun/2012:09:56:14 -0400] Adding end banner page "none" to job 14474.
I [06/Jun/2012:09:56:14 -0400] Job 14474 queued on 'usbmpr2051' by 'root'.
D [06/Jun/2012:09:56:14 -0400] Job 14474 hold_until = 0
D [06/Jun/2012:09:56:14 -0400] StartJob(14474, 0x552abf7840)
D [06/Jun/2012:09:56:14 -0400] StartJob() id = 14474, file = 0/1
D [06/Jun/2012:09:56:14 -0400] job-sheets=none,none
D [06/Jun/2012:09:56:14 -0400] banner_page = 0
D [06/Jun/2012:09:56:14 -0400] StartJob: argv = "usbmpr2051","14474","root","testfile.txt","1","cpi=12 lpi=7 page-bottom=86 page-left=57 page-right=57 page-top=72 scaling=100 wrap","/var/spool/cups/d14474-001"
D [06/Jun/2012:09:56:14 -0400] StartJob: envp[0]="PATH=/usr/lib64/cups/filter:/bin:/usr/bin"
D [06/Jun/2012:09:56:14 -0400] StartJob: envp[1]="SOFTWARE=CUPS/1.1"
D [06/Jun/2012:09:56:14 -0400] StartJob: envp[2]="USER=root"
D [06/Jun/2012:09:56:14 -0400] StartJob: envp[3]="CHARSET=utf-8"
D [06/Jun/2012:09:56:14 -0400] StartJob: envp[4]="LANG=en_SG"
D [06/Jun/2012:09:56:14 -0400] StartJob: envp[5]="PPD=/etc/cups/ppd/usbmpr2051.ppd"
D [06/Jun/2012:09:56:14 -0400] StartJob: envp[6]="CUPS_SERVERROOT=/etc/cups"
D [06/Jun/2012:09:56:14 -0400] StartJob: envp[7]="RIP_MAX_CACHE=8m"
D [06/Jun/2012:09:56:14 -0400] StartJob: envp[8]="TMPDIR=/var/spool/cups/tmp"
D [06/Jun/2012:09:56:14 -0400] StartJob: envp[9]="CONTENT_TYPE=text/plain"
D [06/Jun/2012:09:56:14 -0400] StartJob: envp[10]="DEVICE_URI=lpd://usbmps0001/usbmpr2051"
D [06/Jun/2012:09:56:14 -0400] StartJob: envp[11]="PRINTER=usbmpr2051"
D [06/Jun/2012:09:56:14 -0400] StartJob: envp[12]="CUPS_DATADIR=/usr/share/cups"
D [06/Jun/2012:09:56:14 -0400] StartJob: envp[13]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [06/Jun/2012:09:56:14 -0400] StartJob: envp[14]="CUPS_SERVER=localhost"
D [06/Jun/2012:09:56:14 -0400] StartJob: envp[15]="IPP_PORT=631"
D [06/Jun/2012:09:56:14 -0400] StartJob: statusfds = [ 8 11 ]
D [06/Jun/2012:09:56:14 -0400] StartJob: filterfds[1] = [ 12 -1 ]
D [06/Jun/2012:09:56:14 -0400] StartJob: filter = "/usr/lib64/cups/filter/texttops"
D [06/Jun/2012:09:56:14 -0400] StartJob: filterfds[0] = [ 13 14 ]
D [06/Jun/2012:09:56:14 -0400] start_process("/usr/lib64/cups/filter/texttops", 0x7fbffee800, 0x7fbffed9e0, 12, 14, 11)
I [06/Jun/2012:09:56:14 -0400] Started filter /usr/lib64/cups/filter/texttops (PID 23762) for job 14474.
D [06/Jun/2012:09:56:14 -0400] StartJob: filter = "/usr/lib64/cups/filter/pstops"
D [06/Jun/2012:09:56:14 -0400] StartJob: filterfds[1] = [ 12 15 ]
D [06/Jun/2012:09:56:14 -0400] start_process("/usr/lib64/cups/filter/pstops", 0x7fbffee800, 0x7fbffed9e0, 13, 15, 11)
I [06/Jun/2012:09:56:14 -0400] Started filter /usr/lib64/cups/filter/pstops (PID 23763) for job 14474.
D [06/Jun/2012:09:56:14 -0400] StartJob: filter = "/usr/lib64/cups/filter/foomatic-rip"
D [06/Jun/2012:09:56:14 -0400] StartJob: filterfds[0] = [ 13 14 ]
D [06/Jun/2012:09:56:14 -0400] start_process("/usr/lib64/cups/filter/foomatic-rip", 0x7fbffee800, 0x7fbffed9e0, 12, 14, 11)
I [06/Jun/2012:09:56:14 -0400] Started filter /usr/lib64/cups/filter/foomatic-rip (PID 23764) for job 14474.
D [06/Jun/2012:09:56:14 -0400] StartJob: backend = "/usr/lib64/cups/backend/lpd"
D [06/Jun/2012:09:56:14 -0400] StartJob: filterfds[1] = [ -1 12 ]
D [06/Jun/2012:09:56:14 -0400] start_process("/usr/lib64/cups/backend/lpd", 0x7fbffee800, 0x7fbffed9e0, 13, 12, 11)
I [06/Jun/2012:09:56:14 -0400] Started backend /usr/lib64/cups/backend/lpd (PID 23765) for job 14474.
D [06/Jun/2012:09:56:14 -0400] ProcessIPPRequest: 9 status_code=0
D [06/Jun/2012:09:56:14 -0400] CloseClient: 9
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Page = 595x842; 0,0 to 595,842
D [06/Jun/2012:09:56:14 -0400] [Job 14474] ppd->num_fonts = 35
D [06/Jun/2012:09:56:14 -0400] [Job 14474] ppd->fonts[0] = AvantGarde-Book
D [06/Jun/2012:09:56:14 -0400] [Job 14474] ppd->fonts[1] = AvantGarde-BookOblique
D [06/Jun/2012:09:56:14 -0400] [Job 14474] ppd->fonts[2] = AvantGarde-Demi
D [06/Jun/2012:09:56:14 -0400] [Job 14474] ppd->fonts[3] = AvantGarde-DemiOblique
D [06/Jun/2012:09:56:14 -0400] [Job 14474] ppd->fonts[4] = Bookman-Demi
D [06/Jun/2012:09:56:14 -0400] [Job 14474] ppd->fonts[28] = Symbol
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Page = 595x842; 0,0 to 595,842
D [06/Jun/2012:09:56:14 -0400] [Job 14474] slowcollate=0, slowduplex=0, sloworder=0
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%BoundingBox: 0 0 595 842
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%Creator: texttops/CUPS v1.1.22rc1
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%CreationDate: Wednesday 06,June,2012 09:56:14 AM EDT
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%Title: testfile.txt
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%For: root
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%Pages: (atend)
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%DocumentNeededResources: font Courier-Bold
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%+ font Courier
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%+ font Symbol
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%DocumentSuppliedResources: procset texttops 1.1 0
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%+ font Courier-Bold
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%+ font Courier
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%+ font Symbol
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%EndComments
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%BeginProlog
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%BeginResource: font Courier-Bold
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%CreationDate: Wed Dec 22 1999
D [06/Jun/2012:09:56:14 -0400] [Job 14474] foomatic-rip version $Revision: 3.43.2.6 $ running...
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Parsing PPD file ...
D [06/Jun/2012:09:56:14 -0400] [Job 14474] *cupsFilter: "application/vnd.cups-postscript 0 foomatic-rip"
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Added option ColorSpace
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Added option PageSize
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Added option PageRegion
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Added option ImageableArea
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Added option PaperDimension
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Added option Duplex
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Added option Resolution
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Added option PreFilter
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Added option Font
D [06/Jun/2012:09:56:14 -0400] [Job 14474]
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Parameter Summary
D [06/Jun/2012:09:56:14 -0400] [Job 14474] -----------------
D [06/Jun/2012:09:56:14 -0400] [Job 14474]
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Spooler: cups
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Printer: usbmpr2051
D [06/Jun/2012:09:56:14 -0400] [Job 14474] PPD file: /etc/cups/ppd/usbmpr2051.ppd
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Printer model: Generic PostScript Printer Foomatic/Postscript (recommended)
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Job title: testfile.txt
D [06/Jun/2012:09:56:14 -0400] [Job 14474] File(s) to be printed:
D [06/Jun/2012:09:56:14 -0400] [Job 14474] <STDIN>
D [06/Jun/2012:09:56:14 -0400] [Job 14474]
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Pondering option 'cpi=12'
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Unknown option cpi=12.
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Pondering option 'lpi=7'
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Unknown option lpi=7.
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Pondering option 'page-bottom=86'
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Unknown option page-bottom=86.
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Pondering option 'page-left=57'
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Unknown option page-left=57.
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Pondering option 'page-right=57'
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Unknown option page-right=57.
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Pondering option 'page-top=72'
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Unknown option page-top=72.
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Pondering option 'scaling=100'
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Unknown option scaling=100.
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Pondering option 'wrap'
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Unknown boolean option "wrap".
D [06/Jun/2012:09:56:14 -0400] [Job 14474]
D [06/Jun/2012:09:56:14 -0400] [Job 14474] ================================================
D [06/Jun/2012:09:56:14 -0400] [Job 14474]
D [06/Jun/2012:09:56:14 -0400] [Job 14474] File: <STDIN>
D [06/Jun/2012:09:56:14 -0400] [Job 14474]
D [06/Jun/2012:09:56:14 -0400] [Job 14474] ================================================
D [06/Jun/2012:09:56:14 -0400] [Job 14474]
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Reading PostScript input ...
D [06/Jun/2012:09:56:14 -0400] [Job 14474] --> This document is DSC-conforming!
D [06/Jun/2012:09:56:14 -0400] [Job 14474]
D [06/Jun/2012:09:56:14 -0400] [Job 14474] -----------
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Found: %%BeginProlog
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%EndResource
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%BeginResource: font Courier
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%CreationDate: Wed Dec 22 1999
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%EndResource
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%BeginResource: font Symbol
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%CreationDate: Thu Oct 21 1999
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%EndResource
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%BeginResource: procset texttops 1.1 0
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%EndResource
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%EndProlog
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%Page: 1 1
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%Page: 1 1
D [06/Jun/2012:09:56:14 -0400] [Job 14474] pw = 481.0, pl = 684.0
D [06/Jun/2012:09:56:14 -0400] [Job 14474] PageLeft = 57.0, PageRight = 538.0
D [06/Jun/2012:09:56:14 -0400] [Job 14474] PageTop = 770.0, PageBottom = 86.0
D [06/Jun/2012:09:56:14 -0400] [Job 14474] PageWidth = 595.0, PageLength = 842.0
D [06/Jun/2012:09:56:14 -0400] [Job 14474] 0 %%Trailer
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Saw Trailer!
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Saw EOF!
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Found: %%EndProlog
D [06/Jun/2012:09:56:14 -0400] [Job 14474]
D [06/Jun/2012:09:56:14 -0400] [Job 14474] -----------
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Found: %%BeginSetup
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Inserting PostScript code for CUPS' page accounting
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Found: %%BeginFeature: *PageSize A4
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Option: PageSize=A4 --> Option will be set by PostScript interpreter
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Found: %%BeginFeature: *PreFilter No
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Option: PreFilter=No --> Setting option
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Found: %% FoomaticRIPOptionSetting: PreFilter=No
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Option: PreFilter=No --> Setting option
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Found: %%BeginFeature: *Resolution default
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Option: Resolution=default --> Setting option
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Found: %% FoomaticRIPOptionSetting: Resolution=default
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Option: Resolution=default --> Setting option
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Found: %%BeginFeature: *Duplex Notcapable
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Option: Duplex=Notcapable --> Setting option
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Found: %% FoomaticRIPOptionSetting: Duplex=Notcapable
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Option: Duplex=Notcapable --> Setting option
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Found: %%EndSetup
D [06/Jun/2012:09:56:14 -0400] [Job 14474]
D [06/Jun/2012:09:56:14 -0400] [Job 14474] -----------
D [06/Jun/2012:09:56:14 -0400] [Job 14474] New page: 1 1
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Inserting option code into "PageSetup" section.
D [06/Jun/2012:09:56:14 -0400] [Job 14474] No page header or page header not DSC-conforming
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Flushing FIFO.
D [06/Jun/2012:09:56:14 -0400] [Job 14474]
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Starting renderer
D [06/Jun/2012:09:56:14 -0400] [Job 14474] JCL: <job data>
D [06/Jun/2012:09:56:14 -0400] [Job 14474]
D [06/Jun/2012:09:56:14 -0400] [Job 14474] renderer PID kid4=23767
D [06/Jun/2012:09:56:14 -0400] [Job 14474] renderer command: level=0; printf "%%!\n%%%% %%%%\n"; if (( $level > 0 )); then if (( $level < 99 )); then level=" -dLanguageLevel=$level"; else level=""; fi; gs -q -dPARANOIDSAFER -dNOPAUSE -dBATCH -sDEVICE=pswrite$level -sOutputFile=- -; else cat; fi
D [06/Jun/2012:09:56:14 -0400] [Job 14474]
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Closing renderer
D [06/Jun/2012:09:56:14 -0400] [Job 14474] KID3 exited with status 0
D [06/Jun/2012:09:56:14 -0400] [Job 14474] tail process done writing data to STDOUT
D [06/Jun/2012:09:56:14 -0400] [Job 14474] KID4 finished
D [06/Jun/2012:09:56:14 -0400] [Job 14474] KID4 exited with status 0
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Renderer exit stat: 0
D [06/Jun/2012:09:56:14 -0400] [Job 14474] KID3 finished
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Renderer process finished
D [06/Jun/2012:09:56:14 -0400] [Job 14474]
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Closing foomatic-rip.
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Connected on ports 515 (local 1023)...
D [06/Jun/2012:09:56:14 -0400] [Job 14474] lpd_command 02 usbmpr2051
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Sending command string (12 bytes)...
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Reading command status...
D [06/Jun/2012:09:56:14 -0400] [Job 14474] lpd_command returning 0
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Control file is:
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Hbloch2
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Proot
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Jtestfile_txt
D [06/Jun/2012:09:56:14 -0400] [Job 14474] ldfA765bloch2
D [06/Jun/2012:09:56:14 -0400] [Job 14474] UdfA765bloch2
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Ntestfile_txt
D [06/Jun/2012:09:56:14 -0400] [Job 14474] lpd_command 02 70 cfA765bloch2
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Sending command string (17 bytes)...
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Reading command status...
D [06/Jun/2012:09:56:14 -0400] [Job 14474] lpd_command returning 0
D [06/Jun/2012:09:56:14 -0400] [Job 14474] lpd_command 03 286363 dfA765bloch2
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Sending command string (21 bytes)...
D [06/Jun/2012:09:56:14 -0400] [Job 14474] Reading command status...
D [06/Jun/2012:09:56:14 -0400] [Job 14474] lpd_command returning 0
D [06/Jun/2012:09:56:14 -0400] UpdateJob: job 14474, file 0 is complete.
D [06/Jun/2012:09:56:14 -0400] CancelJob: id = 14474
D [06/Jun/2012:09:56:14 -0400] StopJob: id = 14474, force = 0
D [06/Jun/2012:09:56:14 -0400] StopJob: printer state is 3
D [06/Jun/2012:09:56:17 -0400] ReadClient: 6 POST / HTTP/1.1
D [06/Jun/2012:09:56:17 -0400] ProcessIPPRequest: 6 status_code=0
D [06/Jun/2012:10:20:03 -0400] ReadClient: 8 POST / HTTP/1.1
D [06/Jun/2012:10:20:03 -0400] ProcessIPPRequest: 8 status_code=0
D [06/Jun/2012:10:20:03 -0400] CloseClient: 8
D [06/Jun/2012:10:20:03 -0400] AcceptClient: 8 from localhost:631.
D [06/Jun/2012:10:20:03 -0400] ReadClient: 8 POST /printers/usbmpr2051 HTTP/1.1
D [06/Jun/2012:10:20:03 -0400] print_job: auto-typing file...
D [06/Jun/2012:10:20:03 -0400] print_job: request file type is text/plain.
D [06/Jun/2012:10:20:03 -0400] CancelJob: id = 13975
D [06/Jun/2012:10:20:03 -0400] check_quotas: requesting-user-name = 'chemist'
D [06/Jun/2012:10:20:03 -0400] print_job: requesting-user-name = 'chemist'
I [06/Jun/2012:10:20:03 -0400] Adding start banner page "none" to job 14475.
I [06/Jun/2012:10:20:03 -0400] Adding end banner page "none" to job 14475.
I [06/Jun/2012:10:20:03 -0400] Job 14475 queued on 'usbmpr2051' by 'chemist'.
D [06/Jun/2012:10:20:03 -0400] Job 14475 hold_until = 0
D [06/Jun/2012:10:20:03 -0400] StartJob(14475, 0x552abf7840)
D [06/Jun/2012:10:20:03 -0400] StartJob() id = 14475, file = 0/1
D [06/Jun/2012:10:20:03 -0400] job-sheets=none,none
D [06/Jun/2012:10:20:03 -0400] banner_page = 0
D [06/Jun/2012:10:20:03 -0400] StartJob: argv = "usbmpr2051","14475","chemist","(stdin)","1","cpi=12 lpi=7 page-bottom=86 page-left=57 page-right=57 page-top=72 scaling=100 wrap","/var/spool/cups/d14475-001"
D [06/Jun/2012:10:20:03 -0400] StartJob: envp[0]="PATH=/usr/lib64/cups/filter:/bin:/usr/bin"
D [06/Jun/2012:10:20:03 -0400] StartJob: envp[1]="SOFTWARE=CUPS/1.1"
D [06/Jun/2012:10:20:03 -0400] StartJob: envp[2]="USER=root"
D [06/Jun/2012:10:20:03 -0400] StartJob: envp[3]="CHARSET=utf-8"
D [06/Jun/2012:10:20:03 -0400] StartJob: envp[4]="LANG=en_SG"
D [06/Jun/2012:10:20:03 -0400] StartJob: envp[5]="PPD=/etc/cups/ppd/usbmpr2051.ppd"
D [06/Jun/2012:10:20:03 -0400] StartJob: envp[6]="CUPS_SERVERROOT=/etc/cups"
D [06/Jun/2012:10:20:03 -0400] StartJob: envp[7]="RIP_MAX_CACHE=8m"
D [06/Jun/2012:10:20:03 -0400] StartJob: envp[8]="TMPDIR=/var/spool/cups/tmp"
D [06/Jun/2012:10:20:03 -0400] StartJob: envp[9]="CONTENT_TYPE=text/plain"
D [06/Jun/2012:10:20:03 -0400] StartJob: envp[10]="DEVICE_URI=lpd://usbmps0001/usbmpr2051"
D [06/Jun/2012:10:20:03 -0400] StartJob: envp[11]="PRINTER=usbmpr2051"
D [06/Jun/2012:10:20:03 -0400] StartJob: envp[12]="CUPS_DATADIR=/usr/share/cups"
D [06/Jun/2012:10:20:03 -0400] StartJob: envp[13]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [06/Jun/2012:10:20:03 -0400] StartJob: envp[14]="CUPS_SERVER=localhost"
D [06/Jun/2012:10:20:03 -0400] StartJob: envp[15]="IPP_PORT=631"
D [06/Jun/2012:10:20:03 -0400] StartJob: statusfds = [ 9 11 ]
D [06/Jun/2012:10:20:03 -0400] StartJob: filterfds[1] = [ 12 -1 ]
D [06/Jun/2012:10:20:03 -0400] StartJob: filter = "/usr/lib64/cups/filter/texttops"
D [06/Jun/2012:10:20:03 -0400] StartJob: filterfds[0] = [ 13 14 ]
D [06/Jun/2012:10:20:03 -0400] start_process("/usr/lib64/cups/filter/texttops", 0x7fbffee800, 0x7fbffed9e0, 12, 14, 11)
I [06/Jun/2012:10:20:03 -0400] Started filter /usr/lib64/cups/filter/texttops (PID 27936) for job 14475.
D [06/Jun/2012:10:20:03 -0400] StartJob: filter = "/usr/lib64/cups/filter/pstops"
D [06/Jun/2012:10:20:03 -0400] StartJob: filterfds[1] = [ 12 15 ]
D [06/Jun/2012:10:20:03 -0400] start_process("/usr/lib64/cups/filter/pstops", 0x7fbffee800, 0x7fbffed9e0, 13, 15, 11)
I [06/Jun/2012:10:20:03 -0400] Started filter /usr/lib64/cups/filter/pstops (PID 27937) for job 14475.
D [06/Jun/2012:10:20:03 -0400] StartJob: filter = "/usr/lib64/cups/filter/foomatic-rip"
D [06/Jun/2012:10:20:03 -0400] StartJob: filterfds[0] = [ 13 14 ]
D [06/Jun/2012:10:20:03 -0400] start_process("/usr/lib64/cups/filter/foomatic-rip", 0x7fbffee800, 0x7fbffed9e0, 12, 14, 11)
I [06/Jun/2012:10:20:03 -0400] Started filter /usr/lib64/cups/filter/foomatic-rip (PID 27938) for job 14475.
D [06/Jun/2012:10:20:03 -0400] StartJob: backend = "/usr/lib64/cups/backend/lpd"
D [06/Jun/2012:10:20:03 -0400] StartJob: filterfds[1] = [ -1 12 ]
D [06/Jun/2012:10:20:03 -0400] start_process("/usr/lib64/cups/backend/lpd", 0x7fbffee800, 0x7fbffed9e0, 13, 12, 11)
I [06/Jun/2012:10:20:03 -0400] Started backend /usr/lib64/cups/backend/lpd (PID 27939) for job 14475.
D [06/Jun/2012:10:20:03 -0400] ProcessIPPRequest: 8 status_code=0
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Page = 595x842; 0,0 to 595,842
D [06/Jun/2012:10:20:03 -0400] [Job 14475] ppd->num_fonts = 35
D [06/Jun/2012:10:20:03 -0400] [Job 14475] ppd->fonts[0] = AvantGarde-Book
D [06/Jun/2012:10:20:03 -0400] [Job 14475] ppd->fonts[1] = AvantGarde-BookOblique
D [06/Jun/2012:10:20:03 -0400] [Job 14475] ppd->fonts[28] = Symbol
D [06/Jun/2012:10:20:03 -0400] ReadClient: 6 POST /printers/usbmpr2051 HTTP/1.1
D [06/Jun/2012:10:20:03 -0400] ProcessIPPRequest: 6 status_code=0
D [06/Jun/2012:10:20:03 -0400] CloseClient: 8
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Page = 595x842; 0,0 to 595,842
D [06/Jun/2012:10:20:03 -0400] [Job 14475] slowcollate=0, slowduplex=0, sloworder=0
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%BoundingBox: 0 0 595 842
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%Creator: texttops/CUPS v1.1.22rc1
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%CreationDate: Wednesday 06,June,2012 10:20:03 AM EDT
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%Title: (stdin)
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%For: chemist
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%Pages: (atend)
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%DocumentNeededResources: font Courier-Bold
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%+ font Courier
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%+ font Symbol
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%DocumentSuppliedResources: procset texttops 1.1 0
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%+ font Courier-Bold
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%+ font Courier
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%+ font Symbol
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%EndComments
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%BeginProlog
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%BeginResource: font Courier-Bold
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%CreationDate: Wed Dec 22 1999
D [06/Jun/2012:10:20:03 -0400] ReadClient: 6 POST /printers/usbmpr2051 HTTP/1.1
D [06/Jun/2012:10:20:03 -0400] [Job 14475] foomatic-rip version $Revision: 3.43.2.6 $ running...
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Parsing PPD file ...
D [06/Jun/2012:10:20:03 -0400] [Job 14475] *cupsFilter: "application/vnd.cups-postscript 0 foomatic-rip"
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Added option ColorSpace
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Added option PageSize
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Added option PageRegion
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Added option ImageableArea
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Added option PaperDimension
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Added option Duplex
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Added option Resolution
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Added option PreFilter
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Added option Font
D [06/Jun/2012:10:20:03 -0400] [Job 14475]
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Parameter Summary
D [06/Jun/2012:10:20:03 -0400] [Job 14475] -----------------
D [06/Jun/2012:10:20:03 -0400] [Job 14475]
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Spooler: cups
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Printer: usbmpr2051
D [06/Jun/2012:10:20:03 -0400] [Job 14475] PPD file: /etc/cups/ppd/usbmpr2051.ppd
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Printer model: Generic PostScript Printer Foomatic/Postscript (recommended)
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Job title: stdin
D [06/Jun/2012:10:20:03 -0400] [Job 14475] File(s) to be printed:
D [06/Jun/2012:10:20:03 -0400] [Job 14475] <STDIN>
D [06/Jun/2012:10:20:03 -0400] [Job 14475]
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Pondering option 'cpi=12'
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Unknown option cpi=12.
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Pondering option 'lpi=7'
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Unknown option lpi=7.
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Pondering option 'page-bottom=86'
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Unknown option page-bottom=86.
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Pondering option 'page-left=57'
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Unknown option page-left=57.
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Pondering option 'page-right=57'
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Unknown option page-right=57.
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Pondering option 'page-top=72'
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Unknown option page-top=72.
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Pondering option 'scaling=100'
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Unknown option scaling=100.
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Pondering option 'wrap'
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Unknown boolean option "wrap".
D [06/Jun/2012:10:20:03 -0400] [Job 14475]
D [06/Jun/2012:10:20:03 -0400] [Job 14475] ================================================
D [06/Jun/2012:10:20:03 -0400] [Job 14475]
D [06/Jun/2012:10:20:03 -0400] [Job 14475] File: <STDIN>
D [06/Jun/2012:10:20:03 -0400] [Job 14475]
D [06/Jun/2012:10:20:03 -0400] [Job 14475] ================================================
D [06/Jun/2012:10:20:03 -0400] [Job 14475]
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Reading PostScript input ...
D [06/Jun/2012:10:20:03 -0400] [Job 14475] --> This document is DSC-conforming!
D [06/Jun/2012:10:20:03 -0400] [Job 14475]
D [06/Jun/2012:10:20:03 -0400] [Job 14475] -----------
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Found: %%BeginProlog
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%EndResource
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%BeginResource: font Courier
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%CreationDate: Wed Dec 22 1999
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%EndResource
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%BeginResource: font Symbol
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%CreationDate: Thu Oct 21 1999
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%EndResource
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%BeginResource: procset texttops 1.1 0
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%EndResource
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%EndProlog
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%Page: 1 1
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%Page: 1 1
D [06/Jun/2012:10:20:03 -0400] [Job 14475] pw = 481.0, pl = 684.0
D [06/Jun/2012:10:20:03 -0400] [Job 14475] PageLeft = 57.0, PageRight = 538.0
D [06/Jun/2012:10:20:03 -0400] [Job 14475] PageTop = 770.0, PageBottom = 86.0
D [06/Jun/2012:10:20:03 -0400] [Job 14475] PageWidth = 595.0, PageLength = 842.0
D [06/Jun/2012:10:20:03 -0400] [Job 14475] 0 %%Trailer
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Saw Trailer!
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Saw EOF!
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Found: %%EndProlog
D [06/Jun/2012:10:20:03 -0400] [Job 14475]
D [06/Jun/2012:10:20:03 -0400] [Job 14475] -----------
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Found: %%BeginSetup
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Inserting PostScript code for CUPS' page accounting
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Found: %%BeginFeature: *PageSize A4
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Option: PageSize=A4 --> Option will be set by PostScript interpreter
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Found: %%BeginFeature: *PreFilter No
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Option: PreFilter=No --> Setting option
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Found: %% FoomaticRIPOptionSetting: PreFilter=No
D [06/Jun/2012:10:20:03 -0400] ProcessIPPRequest: 6 status_code=0
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Option: PreFilter=No --> Setting option
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Found: %%BeginFeature: *Resolution default
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Option: Resolution=default --> Setting option
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Found: %% FoomaticRIPOptionSetting: Resolution=default
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Option: Resolution=default --> Setting option
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Found: %%BeginFeature: *Duplex Notcapable
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Option: Duplex=Notcapable --> Setting option
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Found: %% FoomaticRIPOptionSetting: Duplex=Notcapable
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Option: Duplex=Notcapable --> Setting option
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Found: %%EndSetup
D [06/Jun/2012:10:20:03 -0400] [Job 14475]
D [06/Jun/2012:10:20:03 -0400] [Job 14475] -----------
D [06/Jun/2012:10:20:03 -0400] [Job 14475] New page: 1 1
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Inserting option code into "PageSetup" section.
D [06/Jun/2012:10:20:03 -0400] [Job 14475] No page header or page header not DSC-conforming
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Flushing FIFO.
D [06/Jun/2012:10:20:03 -0400] [Job 14475]
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Starting renderer
D [06/Jun/2012:10:20:03 -0400] [Job 14475] JCL: <job data>
D [06/Jun/2012:10:20:03 -0400] [Job 14475]
D [06/Jun/2012:10:20:03 -0400] [Job 14475] renderer PID kid4=27943
D [06/Jun/2012:10:20:03 -0400] [Job 14475] renderer command: level=0; printf "%%!\n%%%% %%%%\n"; if (( $level > 0 )); then if (( $level < 99 )); then level=" -dLanguageLevel=$level"; else level=""; fi; gs -q -dPARANOIDSAFER -dNOPAUSE -dBATCH -sDEVICE=pswrite$level -sOutputFile=- -; else cat; fi
D [06/Jun/2012:10:20:03 -0400] [Job 14475]
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Closing renderer
D [06/Jun/2012:10:20:03 -0400] [Job 14475] tail process done writing data to STDOUT
D [06/Jun/2012:10:20:03 -0400] [Job 14475] KID4 finished
D [06/Jun/2012:10:20:03 -0400] [Job 14475] KID4 exited with status 0
D [06/Jun/2012:10:20:03 -0400] [Job 14475] KID3 exited with status 0
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Renderer exit stat: 0
D [06/Jun/2012:10:20:03 -0400] [Job 14475] KID3 finished
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Renderer process finished
D [06/Jun/2012:10:20:03 -0400] [Job 14475]
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Closing foomatic-rip.
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Connected on ports 515 (local 1023)...
D [06/Jun/2012:10:20:03 -0400] [Job 14475] lpd_command 02 usbmpr2051
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Sending command string (12 bytes)...
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Reading command status...
D [06/Jun/2012:10:20:03 -0400] [Job 14475] lpd_command returning 0
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Control file is:
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Hbloch2
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Pchemist
D [06/Jun/2012:10:20:03 -0400] [Job 14475] J_stdin_
D [06/Jun/2012:10:20:03 -0400] [Job 14475] ldfA939bloch2
D [06/Jun/2012:10:20:03 -0400] [Job 14475] UdfA939bloch2
D [06/Jun/2012:10:20:03 -0400] [Job 14475] N_stdin_
D [06/Jun/2012:10:20:03 -0400] [Job 14475] lpd_command 02 63 cfA939bloch2
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Sending command string (17 bytes)...
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Reading command status...
D [06/Jun/2012:10:20:03 -0400] [Job 14475] lpd_command returning 0
D [06/Jun/2012:10:20:03 -0400] [Job 14475] lpd_command 03 287189 dfA939bloch2
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Sending command string (21 bytes)...
D [06/Jun/2012:10:20:03 -0400] [Job 14475] Reading command status...
D [06/Jun/2012:10:20:03 -0400] [Job 14475] lpd_command returning 0
D [06/Jun/2012:10:20:03 -0400] UpdateJob: job 14475, file 0 is complete.
D [06/Jun/2012:10:20:03 -0400] CancelJob: id = 14475
D [06/Jun/2012:10:20:03 -0400] StopJob: id = 14475, force = 0
D [06/Jun/2012:10:20:03 -0400] StopJob: printer state is 3
D [06/Jun/2012:10:20:05 -0400] ReadClient: 6 POST / HTTP/1.1
D [06/Jun/2012:10:20:05 -0400] ProcessIPPRequest: 6 status_code=0
D [06/Jun/2012:10:28:54 -0400] ReadClient: 8 POST / HTTP/1.1
D [06/Jun/2012:10:28:54 -0400] ProcessIPPRequest: 8 status_code=0
D [06/Jun/2012:10:28:54 -0400] CloseClient: 8
D [06/Jun/2012:10:28:54 -0400] AcceptClient: 8 from localhost:631.
D [06/Jun/2012:10:28:54 -0400] ReadClient: 8 POST /jobs/ HTTP/1.1
D [06/Jun/2012:10:28:54 -0400] CancelJob: id = 14464
I [06/Jun/2012:10:28:54 -0400] Job 14464 was cancelled by 'root'.
D [06/Jun/2012:10:28:54 -0400] ProcessIPPRequest: 8 status_code=0
D [06/Jun/2012:10:28:54 -0400] CloseClient: 8
D [06/Jun/2012:10:28:59 -0400] ReadClient: 6 POST / HTTP/1.1
D [06/Jun/2012:10:28:59 -0400] ProcessIPPRequest: 6 status_code=0
D [06/Jun/2012:10:29:00 -0400] AcceptClient: 8 from localhost:631.
D [06/Jun/2012:10:29:00 -0400] AcceptClient: 9 from localhost:631.
D [06/Jun/2012:10:29:00 -0400] ReadClient: 9 POST / HTTP/1.1
D [06/Jun/2012:10:29:00 -0400] ProcessIPPRequest: 9 status_code=1
D [06/Jun/2012:10:29:00 -0400] ReadClient: 9 POST / HTTP/1.1
D [06/Jun/2012:10:29:00 -0400] ProcessIPPRequest: 9 status_code=1
D [06/Jun/2012:10:29:00 -0400] ReadClient: 9 POST / HTTP/1.1
D [06/Jun/2012:10:29:00 -0400] ProcessIPPRequest: 9 status_code=0
D [06/Jun/2012:10:29:00 -0400] CloseClient: 9
D [06/Jun/2012:10:29:00 -0400] ReadClient: 8 POST / HTTP/1.1
D [06/Jun/2012:10:29:00 -0400] ProcessIPPRequest: 8 status_code=0
D [06/Jun/2012:10:29:00 -0400] ReadClient: 8 POST / HTTP/1.1
D [06/Jun/2012:10:29:59 -0400] ProcessIPPRequest: 6 status_code=0
I [06/Jun/2012:10:30:00 -0400] Scheduler shutting down normally.
D [06/Jun/2012:10:30:00 -0400] CloseClient: 6
D [06/Jun/2012:10:30:00 -0400] StopListening: closing all listen sockets.
D [06/Jun/2012:10:30:00 -0400] PauseListening: clearing input bits...
D [06/Jun/2012:10:30:00 -0400] AddLocation: added location '/'
D [06/Jun/2012:10:30:00 -0400] DenyIP: / deny 00000000/00000000
D [06/Jun/2012:10:30:00 -0400] AllowIP: / allow 7f000001/ffffffff
D [06/Jun/2012:10:30:00 -0400] AddLocation: added location '/admin'
D [06/Jun/2012:10:30:00 -0400] DenyIP: /admin deny 00000000/00000000
D [06/Jun/2012:10:30:00 -0400] AllowIP: /admin allow 7f000001/ffffffff
D [06/Jun/2012:10:30:00 -0400] AddLocation: added location '/printers/usbmpr2045'
D [06/Jun/2012:10:30:00 -0400] DenyIP: /printers/usbmpr2045 deny 00000000/00000000
D [06/Jun/2012:10:30:00 -0400] AllowIP: /printers/usbmpr2045 allow 7f000001/ffffffff
D [06/Jun/2012:10:30:00 -0400] AddLocation: added location '/printers/usbmpr2051'
D [06/Jun/2012:10:30:00 -0400] DenyIP: /printers/usbmpr2051 deny 00000000/00000000
D [06/Jun/2012:10:30:00 -0400] AllowIP: /printers/usbmpr2051 allow 7f000001/ffffffff
D [06/Jun/2012:10:30:00 -0400] AddLocation: added location '/printers/ng_unifyR'
D [06/Jun/2012:10:30:00 -0400] DenyIP: /printers/ng_unifyR deny 00000000/00000000
D [06/Jun/2012:10:30:00 -0400] AllowIP: /printers/ng_unifyR allow 7f000001/ffffffff
D [06/Jun/2012:10:30:00 -0400] AddLocation: added location 'CUPS_INTERNAL_BROWSE_ACL'
D [06/Jun/2012:10:30:00 -0400] AllowHost: CUPS_INTERNAL_BROWSE_ACL allow @LOCAL
I [06/Jun/2012:10:30:00 -0400] Listening to 7f000001:631
I [06/Jun/2012:10:30:00 -0400] Loaded configuration file "/etc/cups/cupsd.conf"
I [06/Jun/2012:10:30:00 -0400] Configured for up to 100 clients.
I [06/Jun/2012:10:30:00 -0400] Allowing up to 100 client connections per host.
I [06/Jun/2012:10:30:00 -0400] Full reload is required.
D [06/Jun/2012:10:30:00 -0400] LoadAllPrinters: Loading printer usbmpr2045...
D [06/Jun/2012:10:30:00 -0400] LoadAllPrinters: Loading printer usbmpr2051...
D [06/Jun/2012:10:30:00 -0400] LoadAllPrinters: Loading printer ng_unifyR...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "http"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "socket"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "usb:/dev/usb/lp0"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "usb:/dev/usb/lp1"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "usb:/dev/usb/lp2"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "usb:/dev/usb/lp3"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "usb:/dev/usb/lp4"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "usb:/dev/usb/lp5"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "usb:/dev/usb/lp6"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "usb:/dev/usb/lp7"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "usb:/dev/usb/lp8"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "usb:/dev/usb/lp9"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "usb:/dev/usb/lp10"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "usb:/dev/usb/lp11"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "usb:/dev/usb/lp12"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "usb:/dev/usb/lp13"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "usb:/dev/usb/lp14"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "usb:/dev/usb/lp15"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "ptal"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "hal"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "lpd"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "epson:/dev/lp0"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "scsi"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "ipp"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "parallel:/dev/lp0"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "serial:/dev/ttyS0?baud=115200"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "serial:/dev/ttyS1?baud=115200"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "serial:/dev/ttyS2?baud=115200"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "serial:/dev/ttyS3?baud=115200"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "serial:/dev/ttyS4?baud=115200"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "serial:/dev/ttyS5?baud=115200"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "serial:/dev/ttyS6?baud=115200"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "serial:/dev/ttyS7?baud=115200"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "canon:/dev/lp0"...
D [06/Jun/2012:10:30:00 -0400] LoadDevices: Added device "smb"...
I [06/Jun/2012:10:30:00 -0400] LoadPPDs: Read "/etc/cups/ppds.dat", 4227 PPDs...
I [06/Jun/2012:10:30:00 -0400] LoadPPDs: No new or changed PPDs...
D [06/Jun/2012:10:30:00 -0400] LoadAllJobs: Scanning /var/spool/cups...
D [06/Jun/2012:10:30:00 -0400] LoadAllJobs: Loading attributes for job 14337...
D [06/Jun/2012:10:30:00 -0400] LoadAllJobs: Loading attributes for job 14395...
D [06/Jun/2012:10:30:00 -0400] LoadAllJobs: Loading attributes for job 14440...
D [06/Jun/2012:10:30:00 -0400] CancelJob: id = 13976
I [06/Jun/2012:10:30:00 -0400] Full reload complete.
D [06/Jun/2012:10:30:00 -0400] StartListening: NumListeners=1
D [06/Jun/2012:10:30:00 -0400] StartListening: address=7f000001 port=631
D [06/Jun/2012:10:30:00 -0400] ResumeListening: setting input bits...
D [06/Jun/2012:10:30:05 -0400] AcceptClient: 6 from localhost:631.
D [06/Jun/2012:10:30:05 -0400] ReadClient: 6 POST / HTTP/1.1
D [06/Jun/2012:10:30:05 -0400] ProcessIPPRequest: 6 status_code=0