unable to print

[ram]

OS:CentOS release 4 (Nahant Update 3) X86_64
CUPS config version: 1.1.22rc1

Printing used to work fine earlier but no print is successful now.

[CODE]
# cat /etc/cups/cupsd.conf|grep -v ^#|grep [:alnum:]
LogFilePerm 0600
MaxLogSize 2000000000
LogLevel debug
Printcap /etc/printcap
<Location />
Order Deny,Allow
Deny From All
Allow From 127.0.0.1
</Location>
<Location /admin>
AuthType Basic
AuthClass System
Order Deny,Allow
Deny From All
Allow From 127.0.0.1
</Location>
<Location /printers/usbmpr2045>
Order Deny,Allow
Deny From All
Allow From 127.0.0.1
AuthType None
</Location>
<Location /printers/usbmpr2051>
Order Deny,Allow
Deny From All
Allow From 127.0.0.1
AuthType None
</Location>
<Location /printers/ng_unifyR>
Order Deny,Allow
Deny From All
Allow From 127.0.0.1
AuthType None
</Location>
Browsing On
BrowseProtocols cups
BrowseOrder Deny,Allow
BrowseAllow from @LOCAL
Listen 127.0.0.1:631
[/CODE]

Earlier there was job sitting in the queue, i even removed it and tried but no luck
[CODE]
# lpq -P <printer_name>
<printer_name> is ready
Rank    Owner   Job     File(s)                         Total Size
1st       bob   14464   plot                            27648 bytes
[/CDOE]

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.

[CODE]
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


[/CODE]