Page 1 (Scheduler not running?): {'cups_connection_failure': False} Page 2 (Choose printer): {'cups_dest': , 'cups_instance': None, 'cups_queue': 'BrotherLaser', 'cups_queue_listed': True} Page 3 (Check printer sanity): {'cups_device_uri_scheme': u'usb', 'cups_printer_dict': {'device-uri': u'usb://Brother/HL-2040%20series', 'printer-info': u'BROTHER HL-2060', 'printer-is-shared': True, 'printer-location': u'', 'printer-make-and-model': u'Brother HL-2060 Foomatic/hl1250 (recommended)', 'printer-state': 3, 'printer-state-message': u'/usr/lib/cups/filter/foomatic-rip failed', 'printer-state-reasons': [u'none'], 'printer-type': 143364, 'printer-uri-supported': u'ipp://localhost:631/printers/BrotherLaser'}, 'cups_printer_remote': False, 'is_cups_class': False} Page 4 (Check PPD sanity): {'cups_printer_ppd_defaults': {u'Adjustment': {u'HalftoningAlgorithm': u'Accurate'}, u'General': {u'EconoMode': u'high', u'InputSlot': u'auto', u'MediaType': u'Plain', u'PageRegion': u'Letter', u'PageSize': u'Letter', u'Resolution': u'600x600dpi'}}, 'cups_printer_ppd_valid': True, 'missing_pkgs_and_exes': ([], [])} Page 5 (Local or remote?): {'printer_is_remote': False} Page 6 (Choose device): {'cups_device_dict': {'device-class': u'direct', 'device-id': u'MFG:Brother;CMD:PJL,HBP;MDL:HL-2040 series;CLS:PRINTER;', 'device-info': u'Brother HL-2040 series USB #1', 'device-make-and-model': u'Brother HL-2040 series'}} Page 7 (Printer state reasons): {'printer-state-message': u'/usr/lib/cups/filter/foomatic-rip failed', 'printer-state-reasons': [u'none']} Page 8 (Error log checkpoint): {'cups_server_settings': {'DefaultAuthType': 'Basic', 'SystemGroup': 'lpadmin', '_debug_logging': '0', '_remote_admin': '0', '_remote_any': '0', '_remote_printers': '1', '_share_printers': '1', '_user_cancel_any': '0'}, 'error_log_checkpoint': 2212L, 'error_log_debug_logging_set': True} Page 9 (Print test page): {'test_page_attempted': True, 'test_page_completions': [(305, u'Job stopped due to filter errors; please consult the error_log file for details.')], 'test_page_job_id': [305], 'test_page_job_status': [(False, 304, 'BrotherLaser', 'Master Subscription Agreement - salesforce.com', 'Stopped', None), (False, 303, 'BrotherLaser', 'The Business of Software - company wants to buy software but with two-way disclaimer', 'Stopped', None), (True, 305, 'BrotherLaser', 'Test Page', 'Stopped', {'attributes-charset': u'utf-8', 'attributes-natural-language': u'en-ca', 'document-format': u'application/postscript', 'fitplot': True, 'job-hold-until': u'no-hold', 'job-id': 305, 'job-k-octets': 17, 'job-media-sheets-completed': 1, 'job-more-info': u'ipp://localhost:631/jobs/305', 'job-name': u'Test Page', 'job-originating-host-name': u'localhost', 'job-originating-user-name': u'cwillu', 'job-preserved': True, 'job-printer-state-message': u'/usr/lib/cups/filter/foomatic-rip failed', 'job-printer-state-reasons': [u'none'], 'job-printer-up-time': 1233162994, 'job-printer-uri': u'ipp://localhost:631/printers/BrotherLaser', 'job-priority': 50, 'job-sheets': [u'none', u'none'], 'job-state': 6, 'job-state-reasons': u'job-stopped', 'job-uri': u'ipp://localhost:631/jobs/305', 'job-uuid': u'urn:uuid:a8d1cbdc-1288-3f28-715e-5f66762db5cb', 'printer-uri': u'ipp://localhost/printers/BrotherLaser', 'time-at-completed': None, 'time-at-creation': 1233162983, 'time-at-processing': 1233162983})], 'test_page_successful': False} Page 10 (Error log fetch): {'error_log': ['D [28/Jan/2009:11:16:06 -0600] cupsdCloseClient: 24', 'D [28/Jan/2009:11:16:06 -0600] cupsdAcceptClient: 24 from localhost (Domain)', 'D [28/Jan/2009:11:16:06 -0600] cupsdReadClient: 24 POST / HTTP/1.1', 'D [28/Jan/2009:11:16:06 -0600] cupsdAuthorize: No authentication data provided.', 'D [28/Jan/2009:11:16:06 -0600] Get-Jobs ipp://localhost/jobs/', 'D [28/Jan/2009:11:16:06 -0600] [Job 304] Loading attributes...', 'D [28/Jan/2009:11:16:06 -0600] cupsdProcessIPPRequest: 24 status_code=0 (successful-ok)', 'D [28/Jan/2009:11:16:06 -0600] cupsdAcceptClient: 25 from localhost (Domain)', 'D [28/Jan/2009:11:16:06 -0600] cupsdCloseClient: 24', 'D [28/Jan/2009:11:16:06 -0600] cupsdReadClient: 25 POST / HTTP/1.1', 'D [28/Jan/2009:11:16:06 -0600] cupsdAuthorize: No authentication data provided.', 'D [28/Jan/2009:11:16:06 -0600] Create-Printer-Subscription /', 'D [28/Jan/2009:11:16:06 -0600] cupsdCreateSubscription(con=0xb8481eb8(25), uri="/")', 'D [28/Jan/2009:11:16:06 -0600] pullmethod="ippget"', 'D [28/Jan/2009:11:16:06 -0600] notify-lease-duration=86400', 'D [28/Jan/2009:11:16:06 -0600] notify-time-interval=0', 'D [28/Jan/2009:11:16:06 -0600] cupsdAddSubscription(mask=17800, dest=(nil)(), job=(nil)(0), uri="(null)")', 'D [28/Jan/2009:11:16:06 -0600] Added subscription 23 for server', 'I [28/Jan/2009:11:16:06 -0600] Saving subscriptions.conf...', 'D [28/Jan/2009:11:16:06 -0600] cupsdProcessIPPRequest: 25 status_code=0 (successful-ok)', 'D [28/Jan/2009:11:16:06 -0600] cupsdCloseClient: 25', 'D [28/Jan/2009:11:16:07 -0600] cupsdAcceptClient: 24 from localhost (Domain)', 'D [28/Jan/2009:11:16:07 -0600] cupsdReadClient: 24 POST / HTTP/1.1', 'D [28/Jan/2009:11:16:07 -0600] cupsdAuthorize: No authentication data provided.', 'D [28/Jan/2009:11:16:07 -0600] Get-Notifications /', 'D [28/Jan/2009:11:16:07 -0600] cupsdIsAuthorized: requesting-user-name="cwillu"', 'D [28/Jan/2009:11:16:07 -0600] cupsdProcessIPPRequest: 24 status_code=0 (successful-ok)', 'D [28/Jan/2009:11:16:07 -0600] cupsdCloseClient: 24', 'D [28/Jan/2009:11:16:23 -0600] cupsdAcceptClient: 24 from localhost (Domain)', 'D [28/Jan/2009:11:16:23 -0600] cupsdReadClient: 24 POST /printers/BrotherLaser HTTP/1.1', 'D [28/Jan/2009:11:16:23 -0600] cupsdAuthorize: No authentication data provided.', 'D [28/Jan/2009:11:16:23 -0600] Print-Job ipp://localhost/printers/BrotherLaser', 'D [28/Jan/2009:11:16:23 -0600] add_job: requesting-user-name="cwillu"', 'D [28/Jan/2009:11:16:23 -0600] Adding default job-sheets values "none,none"...', 'I [28/Jan/2009:11:16:23 -0600] [Job 305] Adding start banner page "none".', 'I [28/Jan/2009:11:16:23 -0600] Saving subscriptions.conf...', 'I [28/Jan/2009:11:16:23 -0600] [Job 305] Adding end banner page "none".', 'I [28/Jan/2009:11:16:23 -0600] [Job 305] File of type application/postscript queued by "cwillu".', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] hold_until=0', 'I [28/Jan/2009:11:16:23 -0600] [Job 305] Queued on "BrotherLaser" by "cwillu".', 'I [28/Jan/2009:11:16:23 -0600] Saving subscriptions.conf...', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] job-sheets=none,none', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] banner_page = 0', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] argv[0]="BrotherLaser"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] argv[1]="305"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] argv[2]="cwillu"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] argv[3]="Test Page"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] argv[4]="1"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] argv[5]="job-uuid=urn:uuid:a8d1cbdc-1288-3f28-715e-5f66762db5cb fitplot"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] argv[6]="/var/spool/cups/d00305-001"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] envp[0]="CUPS_CACHEDIR=/var/cache/cups"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] envp[1]="CUPS_DATADIR=/usr/share/cups"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] envp[6]="CUPS_SERVERROOT=/etc/cups"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] envp[7]="CUPS_STATEDIR=/var/run/cups"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] envp[8]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] envp[9]="SERVER_ADMIN=root@localhost"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] envp[10]="SOFTWARE=CUPS/1.3.9"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] envp[11]="TMPDIR=/var/spool/cups/tmp"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] envp[12]="TZ=America/Regina"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] envp[13]="USER=root"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] envp[14]="CUPS_SERVER=/var/run/cups/cups.sock"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] envp[15]="CUPS_ENCRYPTION=IfRequested"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] envp[16]="IPP_PORT=631"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] envp[17]="CHARSET=utf-8"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] envp[18]="LANG=en_CA.UTF8"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] envp[19]="PPD=/etc/cups/ppd/BrotherLaser.ppd"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] envp[20]="RIP_MAX_CACHE=8m"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] envp[21]="CONTENT_TYPE=application/postscript"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] envp[22]="DEVICE_URI=usb://Brother/HL-2040%20series"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] envp[23]="PRINTER=BrotherLaser"', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] envp[24]="FINAL_CONTENT_TYPE=printer/BrotherLaser"', 'I [28/Jan/2009:11:16:23 -0600] [Job 305] Started filter /usr/lib/cups/filter/pstopdf (PID 24422)', 'I [28/Jan/2009:11:16:23 -0600] [Job 305] Started filter /usr/lib/cups/filter/pdftopdf (PID 24423)', 'I [28/Jan/2009:11:16:23 -0600] [Job 305] Started filter /usr/lib/cups/filter/cpdftocps (PID 24425)', 'I [28/Jan/2009:11:16:23 -0600] [Job 305] Started filter /usr/lib/cups/filter/foomatic-rip (PID 24427)', 'I [28/Jan/2009:11:16:23 -0600] [Job 305] Started backend /usr/lib/cups/backend/usb (PID 24431)', 'I [28/Jan/2009:11:16:23 -0600] Saving subscriptions.conf...', 'D [28/Jan/2009:11:16:23 -0600] cupsdProcessIPPRequest: 24 status_code=0 (successful-ok)', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] pstopdf argv[6] = 305 cwillu Test Page 1 job-uuid=urn:uuid:a8d1cbdc-1288-3f28-715e-5f66762db5cb fitplot /var/spool/cups/d00305-001', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] PPD: /etc/cups/ppd/BrotherLaser.ppd', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] Printer using device file "/dev/usblp0"...', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] backendRunLoop(print_fd=0, device_fd=7, use_bc=0, side_cb=0xb7f31a80)', 'I [28/Jan/2009:11:16:23 -0600] Saving subscriptions.conf...', 'D [28/Jan/2009:11:16:23 -0600] cupsdCloseClient: 24', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] Resolution: 600x600', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] Getting input from file', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] foomatic-rip version 4.0.0.195 running...', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] Parsing PPD file ...', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] Added option PageSize', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] Added option ImageableArea', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] Added option PaperDimension', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] Added option MediaType', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] Added option EconoMode', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] Added option InputSlot', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] Added option Resolution', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] Added option HalftoningAlgorithm', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] Added option Font', 'D [28/Jan/2009:11:16:23 -0600] [Job 305]', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] Parameter Summary', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] -----------------', 'D [28/Jan/2009:11:16:23 -0600] [Job 305]', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] Spooler: cups', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] Printer: BrotherLaser', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] Shell: /bin/bash', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] PPD file: /etc/cups/ppd/BrotherLaser.ppd', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] ATTR file:', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] Printer model: Brother HL-2060 Foomatic/hl1250 (recommended)', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] Job title: Test Page', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] File(s) to be printed:', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] ', 'D [28/Jan/2009:11:16:23 -0600] [Job 305]', "D [28/Jan/2009:11:16:23 -0600] [Job 305] Ghostscript extra search path ('GS_LIB'): /usr/share/cups/fonts", "D [28/Jan/2009:11:16:23 -0600] [Job 305] Pondering option 'job-uuid=urn:uuid:a8d1cbdc-1288-3f28-715e-5f66762db5cb'", 'D [28/Jan/2009:11:16:23 -0600] [Job 305] Unknown option job-uuid=urn:uuid:a8d1cbdc-1288-3f28-715e-5f66762db5cb.', "D [28/Jan/2009:11:16:23 -0600] [Job 305] Pondering option 'fitplot'", 'D [28/Jan/2009:11:16:23 -0600] [Job 305] Unknown boolean option "fitplot".', 'D [28/Jan/2009:11:16:23 -0600] [Job 305]', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] ================================================', 'D [28/Jan/2009:11:16:23 -0600] [Job 305]', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] File: ', 'D [28/Jan/2009:11:16:23 -0600] [Job 305]', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] ================================================', 'D [28/Jan/2009:11:16:23 -0600] [Job 305]', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] Page size: Letter', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] Width: 612, height: 792, absolute margins: , , ,', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] Relative margins: 0, 0, 0, 0', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] PPD options: -r600x600 -dDEVICEWIDTHPOINTS=612 -dDEVICEHEIGHTPOINTS=792', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] PostScript to be injected:', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] Running cat | /usr/bin/ps2pdf13 -dAutoRotatePages=/None -dAutoFilterColorImages=false -dNOPLATFONTS -dPARANOIDSAFER -sstdout=%stderr -dColorImageFilter=/FlateEncode -dPDFSETTINGS=/printer -r600x600 -dDEVICEWIDTHPOINTS=612 -dDEVICEHEIGHTPOINTS=792 - -', 'D [28/Jan/2009:11:16:23 -0600] cupsdAcceptClient: 24 from localhost (Domain)', 'D [28/Jan/2009:11:16:23 -0600] cupsdReadClient: 24 POST / HTTP/1.1', 'D [28/Jan/2009:11:16:23 -0600] cupsdAuthorize: No authentication data provided.', 'D [28/Jan/2009:11:16:23 -0600] Get-Jobs ipp://localhost/jobs/', 'D [28/Jan/2009:11:16:23 -0600] cupsdProcessIPPRequest: 24 status_code=0 (successful-ok)', 'D [28/Jan/2009:11:16:23 -0600] cupsdAcceptClient: 25 from localhost (Domain)', 'D [28/Jan/2009:11:16:23 -0600] cupsdCloseClient: 24', 'D [28/Jan/2009:11:16:23 -0600] cupsdReadClient: 25 POST / HTTP/1.1', 'D [28/Jan/2009:11:16:23 -0600] cupsdAuthorize: No authentication data provided.', 'D [28/Jan/2009:11:16:23 -0600] Get-Notifications /', 'D [28/Jan/2009:11:16:23 -0600] cupsdIsAuthorized: requesting-user-name="cwillu"', 'D [28/Jan/2009:11:16:23 -0600] cupsdProcessIPPRequest: 25 status_code=0 (successful-ok)', 'D [28/Jan/2009:11:16:23 -0600] cupsdReadClient: 25 POST / HTTP/1.1', 'D [28/Jan/2009:11:16:23 -0600] cupsdAuthorize: No authentication data provided.', 'D [28/Jan/2009:11:16:23 -0600] Get-Job-Attributes ipp://localhost/jobs/305', 'D [28/Jan/2009:11:16:23 -0600] cupsdProcessIPPRequest: 25 status_code=0 (successful-ok)', 'D [28/Jan/2009:11:16:23 -0600] cupsdCloseClient: 25', 'D [28/Jan/2009:11:16:23 -0600] cupsdAcceptClient: 24 from localhost (Domain)', 'D [28/Jan/2009:11:16:23 -0600] cupsdReadClient: 24 POST / HTTP/1.1', 'D [28/Jan/2009:11:16:23 -0600] cupsdAuthorize: No authentication data provided.', 'D [28/Jan/2009:11:16:23 -0600] Get-Notifications /', 'D [28/Jan/2009:11:16:23 -0600] cupsdIsAuthorized: requesting-user-name="cwillu"', 'D [28/Jan/2009:11:16:23 -0600] cupsdProcessIPPRequest: 24 status_code=0 (successful-ok)', 'D [28/Jan/2009:11:16:23 -0600] cupsdCloseClient: 24', 'D [28/Jan/2009:11:16:23 -0600] [Job 305] GPL Ghostscript 8.63: Set UseCIEColor for UseDeviceIndependentColor to work properly.', 'D [28/Jan/2009:11:16:24 -0600] PID 24422 (/usr/lib/cups/filter/pstopdf) exited with no errors.', 'D [28/Jan/2009:11:16:24 -0600] PID 24423 (/usr/lib/cups/filter/pdftopdf) exited with no errors.', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Device copies: 1; device collate:', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] pdftops - copying to temp print file "/tmp/498092e886691"', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Page = 612x792; 0,0 to 612,792', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] slow_collate=0, slow_duplex=0, slow_order=0', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Before copy_comments - %!PS-Adobe-3.0', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] %!PS-Adobe-3.0', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] %%LanguageLevel: 3', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] %%DocumentSuppliedResources: (atend)', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] %%DocumentMedia: plain 612 792 0 () ()', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] %%BoundingBox: 0 0 612 792', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] %%Pages: 1', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] %%EndComments', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Before copy_prolog - %%BeginDefaults', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Filetype: PostScript', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Reading PostScript input ...', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] --> This document is DSC-conforming!', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Found %RBINumCopies: 1', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Job claims to be DSC-conforming, but "%%BeginProlog" was missing before first line with another"%%BeginProlog" comment (is this a TeX/LaTeX/dvips-generated PostScript file?). Assuming start of "Prolog" here.', 'D [28/Jan/2009:11:16:24 -0600] [Job 305]', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] -----------', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Found: %%BeginProlog', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Before copy_setup - %%BeginSetup', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Found: %%EndProlog', 'D [28/Jan/2009:11:16:24 -0600] [Job 305]', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] -----------', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Found: %%BeginSetup', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Found: %%BeginFeature: *PageRegion Letter', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Option: PageRegion=Letter', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] --> Option will be set by PostScript interpreter', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Found: %%BeginFeature: *MediaType Plain', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Option: MediaType=Plain', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Setting option', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Found: %% FoomaticRIPOptionSetting: MediaType=Plain', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Option: MediaType=Plain', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Setting option', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Found: %%BeginFeature: *EconoMode high', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Option: EconoMode=high', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Setting option', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Found: %% FoomaticRIPOptionSetting: EconoMode=high', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Option: EconoMode=high', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Setting option', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Found: %%BeginFeature: *InputSlot auto', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Option: InputSlot=auto', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Setting option', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Found: %% FoomaticRIPOptionSetting: InputSlot=auto', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Option: InputSlot=auto', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Setting option', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Found: %%BeginFeature: *Resolution 600x600dpi', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Option: Resolution=600x600dpi', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] --> Option will be set by PostScript interpreter', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Before page loop - %%Page: 1 1', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Copying page 1...', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] pagew = 612.0, pagel = 792.0', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] bboxx = 0, bboxy = 0, bboxw = 612, bboxl = 792', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] PageLeft = 0.0, PageRight = 612.0', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] PageTop = 792.0, PageBottom = 0.0', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] PageWidth = 612.0, PageLength = 792.0', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Found: %%EndSetup', "D [28/Jan/2009:11:16:24 -0600] [Job 305] Inserting PostScript code for CUPS' page accounting", 'D [28/Jan/2009:11:16:24 -0600] [Job 305]', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] -----------', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] New page: %%Page: 1 1', 'D [28/Jan/2009:11:16:24 -0600] [Job 305]', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Found: %%BeginPageSetup', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Inserting option code into "PageSetup" section.', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Found: %%BeginFeature: *HalftoningAlgorithm Accurate', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Option: HalftoningAlgorithm=Accurate', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] --> Option will be set by PostScript interpreter', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Wrote 1 pages...', 'D [28/Jan/2009:11:16:24 -0600] [Job 305] Flushing FIFO.', 'D [28/Jan/2009:11:16:24 -0600] PID 24425 (/usr/lib/cups/filter/cpdftocps) exited with no errors.', 'D [28/Jan/2009:11:16:25 -0600] [Job 305]', 'D [28/Jan/2009:11:16:25 -0600] [Job 305] Starting renderer with command: "gs -sstdout=%stderr -dBATCH -dPARANOIDSAFER -dNOPAUSE -sDEVICE=hl1250 -dEconoMode=2 -dSourceTray=0 -sOutputFile=%stdout -"', 'D [28/Jan/2009:11:16:25 -0600] [Job 305] Starting process "kid3" (generation 1)', 'D [28/Jan/2009:11:16:25 -0600] [Job 305] Starting process "kid4" (generation 2)', 'D [28/Jan/2009:11:16:25 -0600] [Job 305] JCL: \x1b%-12345X@PJL', 'D [28/Jan/2009:11:16:25 -0600] [Job 305] @PJL SET MEDIATYPE=REGULAR', 'D [28/Jan/2009:11:16:25 -0600] [Job 305] \x1b%-12345X@PJL RESET', 'D [28/Jan/2009:11:16:25 -0600] [Job 305]', 'D [28/Jan/2009:11:16:25 -0600] [Job 305]', 'D [28/Jan/2009:11:16:25 -0600] [Job 305] Starting process "renderer" (generation 2)', 'D [28/Jan/2009:11:16:25 -0600] [Job 305] GPL Ghostscript 8.63 (2008-08-01)', 'D [28/Jan/2009:11:16:25 -0600] [Job 305] Copyright (C) 2008 Artifex Software, Inc. All rights reserved.', 'D [28/Jan/2009:11:16:25 -0600] [Job 305] This software comes with NO WARRANTY: see the file PUBLIC for details.', 'D [28/Jan/2009:11:16:25 -0600] [Job 305]', 'D [28/Jan/2009:11:16:25 -0600] [Job 305] Closing renderer', 'I [28/Jan/2009:11:16:26 -0600] Saving subscriptions.conf...', 'D [28/Jan/2009:11:16:26 -0600] [Job 305] Error: /ioerror in --showpage--', 'D [28/Jan/2009:11:16:26 -0600] [Job 305] Operand stack:', 'D [28/Jan/2009:11:16:26 -0600] [Job 305] 1 true', 'D [28/Jan/2009:11:16:26 -0600] [Job 305] Execution stack:', 'D [28/Jan/2009:11:16:26 -0600] [Job 305] %interp_exit .runexec2 --nostringval-- --nostringval-- --nostringval-- 2 %stopped_push --nostringval-- --nostringval-- --nostringval-- false 1 %stopped_push 1905 1 3 %oparray_pop 1904 1 3 %oparray_pop 1888 1 3 %oparray_pop 1771 1 3 %oparray_pop --nostringval-- %errorexec_pop .runexec2 --nostringval-- --nostringval-- --nostringval-- 2 %stopped_push --nostringval-- 1777 0 5 %oparray_pop --nostringval-- --nostringval--', 'D [28/Jan/2009:11:16:26 -0600] [Job 305] Dictionary stack:', 'D [28/Jan/2009:11:16:26 -0600] [Job 305] --dict:1154/1684(ro)(G)-- --dict:1/20(G)-- --dict:77/200(L)-- --dict:70/75(L)-- --dict:18/25(L)--', 'D [28/Jan/2009:11:16:26 -0600] [Job 305] Current allocation mode is local', 'D [28/Jan/2009:11:16:26 -0600] [Job 305] Last OS error: 32', 'D [28/Jan/2009:11:16:26 -0600] [Job 305] GPL Ghostscript 8.63: Unrecoverable error, exit code 1', 'D [28/Jan/2009:11:16:26 -0600] [Job 305] renderer exited with status 1', 'D [28/Jan/2009:11:16:26 -0600] [Job 305] Possible error on renderer command line or PostScript error. Check options.kid3 exited with status 3', 'D [28/Jan/2009:11:16:26 -0600] [Job 305] Process is dying with "Error closing renderer', 'D [28/Jan/2009:11:16:26 -0600] [Job 305] ", exit stat 3', 'D [28/Jan/2009:11:16:26 -0600] [Job 305] Cleaning up...', 'E [28/Jan/2009:11:16:26 -0600] PID 24427 (/usr/lib/cups/filter/foomatic-rip) stopped with status 3!', 'D [28/Jan/2009:11:16:26 -0600] PID 24431 (/usr/lib/cups/backend/usb) exited with no errors.', 'D [28/Jan/2009:11:16:26 -0600] [Job 305] File 0 is complete.', 'E [28/Jan/2009:11:16:26 -0600] [Job 305] Job stopped due to filter errors.', 'I [28/Jan/2009:11:16:26 -0600] Saving subscriptions.conf...', 'I [28/Jan/2009:11:16:26 -0600] Saving subscriptions.conf...', 'D [28/Jan/2009:11:16:26 -0600] cupsdAcceptClient: 25 from localhost (Domain)', 'D [28/Jan/2009:11:16:26 -0600] cupsdReadClient: 25 POST / HTTP/1.1', 'D [28/Jan/2009:11:16:26 -0600] cupsdAuthorize: No authentication data provided.', 'D [28/Jan/2009:11:16:26 -0600] Get-Jobs ipp://localhost/jobs/', 'D [28/Jan/2009:11:16:26 -0600] cupsdProcessIPPRequest: 25 status_code=0 (successful-ok)', 'D [28/Jan/2009:11:16:26 -0600] cupsdCloseClient: 25', 'D [28/Jan/2009:11:16:26 -0600] cupsdAcceptClient: 25 from localhost (Domain)', 'D [28/Jan/2009:11:16:26 -0600] cupsdReadClient: 25 POST / HTTP/1.1', 'D [28/Jan/2009:11:16:26 -0600] cupsdAuthorize: No authentication data provided.', 'D [28/Jan/2009:11:16:26 -0600] Get-Notifications /', 'D [28/Jan/2009:11:16:26 -0600] cupsdIsAuthorized: requesting-user-name="cwillu"', 'D [28/Jan/2009:11:16:26 -0600] cupsdProcessIPPRequest: 25 status_code=0 (successful-ok)', 'D [28/Jan/2009:11:16:26 -0600] cupsdCloseClient: 25', 'D [28/Jan/2009:11:16:26 -0600] cupsdAcceptClient: 25 from localhost (Domain)', 'D [28/Jan/2009:11:16:26 -0600] cupsdReadClient: 25 POST / HTTP/1.1', 'D [28/Jan/2009:11:16:26 -0600] cupsdAuthorize: No authentication data provided.', 'D [28/Jan/2009:11:16:26 -0600] Get-Notifications /', 'D [28/Jan/2009:11:16:26 -0600] cupsdIsAuthorized: requesting-user-name="cwillu"', 'D [28/Jan/2009:11:16:26 -0600] cupsdProcessIPPRequest: 25 status_code=0 (successful-ok)', 'D [28/Jan/2009:11:16:26 -0600] cupsdCloseClient: 25', 'D [28/Jan/2009:11:16:27 -0600] [Job 305] Unloading...', 'D [28/Jan/2009:11:16:34 -0600] cupsdAcceptClient: 25 from localhost (Domain)', 'D [28/Jan/2009:11:16:34 -0600] cupsdReadClient: 25 POST / HTTP/1.1', 'D [28/Jan/2009:11:16:34 -0600] cupsdAuthorize: No authentication data provided.', 'D [28/Jan/2009:11:16:34 -0600] Get-Job-Attributes ipp://localhost/jobs/305', 'D [28/Jan/2009:11:16:34 -0600] [Job 305] Loading attributes...', 'D [28/Jan/2009:11:16:34 -0600] cupsdProcessIPPRequest: 25 status_code=0 (successful-ok)', 'D [28/Jan/2009:11:16:34 -0600] cupsdCloseClient: 25', 'D [28/Jan/2009:11:16:34 -0600] cupsdAcceptClient: 25 from localhost (Domain)', 'D [28/Jan/2009:11:16:34 -0600] cupsdReadClient: 25 POST / HTTP/1.1', 'D [28/Jan/2009:11:16:34 -0600] cupsdAuthorize: No authentication data provided.', 'D [28/Jan/2009:11:16:34 -0600] Cancel-Subscription /', 'D [28/Jan/2009:11:16:34 -0600] cupsdIsAuthorized: requesting-user-name="cwillu"', 'I [28/Jan/2009:11:16:34 -0600] Saving subscriptions.conf...', 'D [28/Jan/2009:11:16:34 -0600] cupsdProcessIPPRequest: 25 status_code=0 (successful-ok)', 'D [28/Jan/2009:11:16:34 -0600] cupsdAcceptClient: 27 from localhost (Domain)', 'D [28/Jan/2009:11:16:34 -0600] cupsdCloseClient: 25', 'D [28/Jan/2009:11:16:34 -0600] cupsdReadClient: 27 GET /admin/log/error_log HTTP/1.1', 'D [28/Jan/2009:11:16:34 -0600] cupsdAuthorize: No authentication data provided.'], 'error_log_debug_logging_unset': True}