A delay of 6-7 minutes between submission and printing of a job..

[Emre Sururi]

When I send a document to the network printer in our office, it takes about 4-7 minutes before the document actually gets printed.

The connection to the printer is through "https", where I also supply my account information. I've installed it using the CUPS web interface and used both existing PPD driver and supplied driver but it didn't made any difference. I thought it was due to printer but I can print from WinXP with no trouble at all, and all the other people using CUPS also have no problem in immediately printing...

I'd really be grateful if someone could help me on the issue... It's going on for about 1.5 years by now and I don't want to keep on adjusting my pace according to these 7 minutes... (sounded a bit like AA meets BSG episode "33".. but I'm really frustrated - any help would be appreciated!)..

My OS details:
Linux 2.6.25.20-114
Kde 3.5.10 on Pardus 2008.2 Canis aureus (But I experienced the same problem with my the previous distribution I was using which was Fedora)

The version of the CUPS: 1.3.9

The connection details to the printer:
https://username:password@srvxxx.tudelft.net/printers/3mE-8D-0-2/.printer

And also https protocol is a symlink to ipp..
husniya backend # ll ipp http https
lrwxrwxrwx 1 root root     3 2008-12-10 10:38 http -> ipp
lrwxrwxrwx 1 root root     3 2008-12-10 10:38 https -> ipp
-rwx------ 1 root root 27492 2008-12-04 14:17 ipp


Printer details from the PPD file:
*ModelName: "NRG MP C2500"
*PCFileName: "NRMPC253.PPD"
*Manufacturer: "NRG"
*Product: "(NRG MP C2500 PS3)"
*PSVersion: "(3015.102) 2"
*ShortNickName: "NRG MP C2500 PS"
*NickName: "NRG MP C2500 PS"

Cupsd.conf:
LogLevel debug
SystemGroup pnpadmin
Listen localhost:631
Listen /var/run/cups/cups.sock
Browsing On
BrowseOrder allow,deny
BrowseAllow all
DefaultAuthType Basic
<Location />
  # Restrict access to the server...
  Order allow,deny
</Location>
<Location /admin>
  Encryption Required
  # Restrict access to the admin pages...
  Order allow,deny
</Location>
<Location /admin/conf>
  AuthType Default
  Require user @SYSTEM
  # Restrict access to the configuration files...
  Order allow,deny
</Location>
<Policy default>
  <Limit Send-Document Send-URI Hold-Job Release-Job Restart-Job Purge-Jobs Set-Job-Attributes Create-Job-Subscription Renew-Subscription Cancel-Subscription Get-Notifications Reprocess-Job Cancel-Current-Job Suspend-Current-Job Resume-Job CUPS-Move-Job>
    Require user @OWNER @SYSTEM
    Order deny,allow
  </Limit>
  <Limit CUPS-Add-Modify-Printer CUPS-Delete-Printer CUPS-Add-Modify-Class CUPS-Delete-Class CUPS-Set-Default>
    AuthType Default
    Require user @SYSTEM
    Order deny,allow
  </Limit>
  <Limit Pause-Printer Resume-Printer Enable-Printer Disable-Printer Pause-Printer-After-Current-Job Hold-New-Jobs Release-Held-New-Jobs Deactivate-Printer Activate-Printer Restart-Printer Shutdown-Printer Startup-Printer Promote-Job Schedule-Job-After CUPS-Accept-Jobs CUPS-Reject-Jobs>
    AuthType Default
    Require user @SYSTEM
    Order deny,allow
  </Limit>
  <Limit CUPS-Authenticate-Job>
    Require user @OWNER @SYSTEM
    Order deny,allow
  </Limit>
  <Limit All>
    Order deny,allow
  </Limit>
</Policy>



And the log related to a sample Job (I truly apologize for including it here but I thought this was also essential.. For the unabridged log file between the initial submission and the acception of the job by the printer with all the other details not limited to lines specifically including "Job 267", please refer to http://www.emresururi.com/cups_error_log.txt (about 190KB) ):

I [25/Mar/2009:11:31:04 +0100] [Job 267] Adding start banner page "none".
I [25/Mar/2009:11:31:04 +0100] [Job 267] Adding end banner page "none".
I [25/Mar/2009:11:31:04 +0100] [Job 267] File of type application/postscript queued by "root".
D [25/Mar/2009:11:31:04 +0100] [Job 267] hold_until=0
I [25/Mar/2009:11:31:04 +0100] [Job 267] Queued on "3mE-8D-0-2" by "root".
D [25/Mar/2009:11:31:04 +0100] [Job 267] job-sheets=none,none
D [25/Mar/2009:11:31:04 +0100] [Job 267] banner_page = 0
D [25/Mar/2009:11:31:04 +0100] [Job 267] argv[0]="3mE-8D-0-2"
D [25/Mar/2009:11:31:04 +0100] [Job 267] argv[1]="267"
D [25/Mar/2009:11:31:04 +0100] [Job 267] argv[2]="root"
D [25/Mar/2009:11:31:04 +0100] [Job 267] argv[3]="2008 - Hart - Phys Rev B preprint - Generating Derivative Structures.pdf"
D [25/Mar/2009:11:31:04 +0100] [Job 267] argv[4]="1"
D [25/Mar/2009:11:31:04 +0100] [Job 267] argv[5]="Duplex=DuplexNoTumble orientation-requested=3 job-uuid=urn:uuid:e152c605-ac33-32b5-5a68-aa89693b5a1f"
D [25/Mar/2009:11:31:04 +0100] [Job 267] argv[6]="/var/spool/cups/d00267-001"
D [25/Mar/2009:11:31:04 +0100] [Job 267] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [25/Mar/2009:11:31:04 +0100] [Job 267] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [25/Mar/2009:11:31:04 +0100] [Job 267] envp[2]="CUPS_DOCROOT=/usr/share/cups/html"
D [25/Mar/2009:11:31:04 +0100] [Job 267] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [25/Mar/2009:11:31:04 +0100] [Job 267] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [25/Mar/2009:11:31:04 +0100] [Job 267] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [25/Mar/2009:11:31:04 +0100] [Job 267] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [25/Mar/2009:11:31:04 +0100] [Job 267] envp[7]="CUPS_STATEDIR=/var/run/cups"
D [25/Mar/2009:11:31:04 +0100] [Job 267] envp[8]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [25/Mar/2009:11:31:04 +0100] [Job 267] envp[9]="SERVER_ADMIN=root at localhost"
D [25/Mar/2009:11:31:04 +0100] [Job 267] envp[10]="SOFTWARE=CUPS/1.3.9"
D [25/Mar/2009:11:31:04 +0100] [Job 267] envp[11]="TMPDIR=/var/spool/cups/tmp"
D [25/Mar/2009:11:31:04 +0100] [Job 267] envp[12]="USER=root"
D [25/Mar/2009:11:31:04 +0100] [Job 267] envp[13]="CUPS_SERVER=/var/run/cups/cups.sock"
D [25/Mar/2009:11:31:04 +0100] [Job 267] envp[14]="CUPS_ENCRYPTION=IfRequested"
D [25/Mar/2009:11:31:04 +0100] [Job 267] envp[15]="IPP_PORT=631"
D [25/Mar/2009:11:31:04 +0100] [Job 267] envp[16]="CHARSET=utf-8"
D [25/Mar/2009:11:31:04 +0100] [Job 267] envp[17]="LANG=en_US.UTF8"
D [25/Mar/2009:11:31:04 +0100] [Job 267] envp[18]="PPD=/etc/cups/ppd/3mE-8D-0-2.ppd"
D [25/Mar/2009:11:31:04 +0100] [Job 267] envp[19]="RIP_MAX_CACHE=8m"
D [25/Mar/2009:11:31:04 +0100] [Job 267] envp[20]="CONTENT_TYPE=application/postscript"
D [25/Mar/2009:11:31:04 +0100] [Job 267] envp[21]="DEVICE_URI=https://srv525.tudelft.net/printers/3mE-8D-0-2/.printer"
D [25/Mar/2009:11:31:04 +0100] [Job 267] envp[22]="PRINTER=3mE-8D-0-2"
D [25/Mar/2009:11:31:04 +0100] [Job 267] envp[23]="FINAL_CONTENT_TYPE=printer/3mE-8D-0-2"
D [25/Mar/2009:11:31:04 +0100] [Job 267] envp[24]="AUTH_U****"
D [25/Mar/2009:11:31:04 +0100] [Job 267] envp[25]="AUTH_P****"
I [25/Mar/2009:11:31:04 +0100] [Job 267] Started filter /usr/lib/cups/filter/pstops (PID 5702)
I [25/Mar/2009:11:31:04 +0100] [Job 267] Started filter /usr/lib/cups/filter/foomatic-rip (PID 5705)
I [25/Mar/2009:11:31:04 +0100] [Job 267] Started backend /usr/lib/cups/backend/https (PID 5706)
D [25/Mar/2009:11:31:04 +0100] [Job 267] Page = 595x842; 12,12 to 583,830
D [25/Mar/2009:11:31:04 +0100] [Job 267] slow_collate=0, slow_duplex=0, slow_order=0
D [25/Mar/2009:11:31:04 +0100] [Job 267] Before copy_comments - %!PS-Adobe-3.0
D [25/Mar/2009:11:31:04 +0100] [Job 267] %!PS-Adobe-3.0
D [25/Mar/2009:11:31:04 +0100] [Job 267] %%Creator: LaTeX with hyperref package
D [25/Mar/2009:11:31:04 +0100] [Job 267] %%Title: 2008 - Hart - Phys Rev B preprint - Generating Derivative Structures.pdf
D [25/Mar/2009:11:31:04 +0100] [Job 267] %%LanguageLevel: 2
D [25/Mar/2009:11:31:04 +0100] [Job 267] %%DocumentSuppliedResources: (atend)
D [25/Mar/2009:11:31:04 +0100] [Job 267] %%DocumentMedia: plain 595 842 0 () ()
D [25/Mar/2009:11:31:04 +0100] [Job 267] %%BoundingBox: 0 0 595 842
D [25/Mar/2009:11:31:04 +0100] [Job 267] %%Pages: 14
D [25/Mar/2009:11:31:04 +0100] [Job 267] %%EndComments
D [25/Mar/2009:11:31:04 +0100] [Job 267] Before copy_prolog - %%BeginDefaults
D [25/Mar/2009:11:31:04 +0100] [Job 267] Before copy_setup - %%BeginSetup
D [25/Mar/2009:11:31:04 +0100] [Job 267] foomatic-rip version $Revision=3.0.2.135$ running...
D [25/Mar/2009:11:31:04 +0100] [Job 267] Parsing PPD file ...
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option ColorSpace
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option Option1
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option Option20
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option Option25
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option Option30
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option Resolution
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option RIPaperPolicy
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option PageSize
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option PageRegion
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option ImageableArea
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option PaperDimension
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option InputSlot
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option LeadingEdge
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option Duplex
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option Collate
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option RIPrintMode
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option Rimagesm
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option ColorModel
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option RPSBitsPerPixel
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option RPSRGBcorrect
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option RPSColorRendDict
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option RPSDitherType
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option RPSBlackMode
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option RPSBlackOverPrint
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option RPSColorSep
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option Rcmyksimulation
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option MediaType
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option OutputBin
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option StapleLocation
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option RIPunch
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option RIOrientOvr
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option RIWatermark
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option RIWMText
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option RIwmFont
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option RIwmSize
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option RIwmAngle
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option RIwmTextStyle
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option ScreenProc
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option Font
D [25/Mar/2009:11:31:04 +0100] [Job 267] *cupsFilter: "application/vnd.cups-postscript 0 foomatic-rip"
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option JobType
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option LockedPrintPassword
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option DocServerPassword
D [25/Mar/2009:11:31:04 +0100] [Job 267] Added option UserCode
D [25/Mar/2009:11:31:04 +0100] [Job 267] The value None for LockedPrintPassword is a predefined choice
D [25/Mar/2009:11:31:04 +0100] [Job 267] The value None for DocServerPassword is a predefined choice
D [25/Mar/2009:11:31:04 +0100] [Job 267] The value None for UserCode is a predefined choice
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] Parameter Summary
D [25/Mar/2009:11:31:04 +0100] [Job 267] -----------------
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] Spooler: cups
D [25/Mar/2009:11:31:04 +0100] [Job 267] Printer: 3mE-8D-0-2
D [25/Mar/2009:11:31:04 +0100] [Job 267] Shell: /bin/sh
D [25/Mar/2009:11:31:04 +0100] [Job 267] PPD file: /etc/cups/ppd/3mE-8D-0-2.ppd
D [25/Mar/2009:11:31:04 +0100] [Job 267] ATTR file:
D [25/Mar/2009:11:31:04 +0100] [Job 267] Printer model: NRG MP C2500 PS
D [25/Mar/2009:11:31:04 +0100] [Job 267] Job title: 2008 - Hart - Phys Rev B preprint - Generating Derivative Structures.pdf
D [25/Mar/2009:11:31:04 +0100] [Job 267] File(s) to be printed:
D [25/Mar/2009:11:31:04 +0100] [Job 267] <STDIN>
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] GhostScript extra search path ('GS_LIB'): /usr/share/cups/fonts
D [25/Mar/2009:11:31:04 +0100] [Job 267] Pondering option 'Duplex=DuplexNoTumble'
D [25/Mar/2009:11:31:04 +0100] [Job 267] Pondering option 'orientation-requested=3'
D [25/Mar/2009:11:31:04 +0100] [Job 267] Unknown option orientation-requested=3.
D [25/Mar/2009:11:31:04 +0100] [Job 267] Pondering option 'job-uuid=urn:uuid:e152c605-ac33-32b5-5a68-aa89693b5a1f'
D [25/Mar/2009:11:31:04 +0100] [Job 267] Unknown option job-uuid=urn:uuid:e152c605-ac33-32b5-5a68-aa89693b5a1f.
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] ================================================
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] File: <STDIN>
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] ================================================
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] Reading PostScript input ...
D [25/Mar/2009:11:31:04 +0100] [Job 267] --> This document is DSC-conforming!
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %RBINumCopies: 1
D [25/Mar/2009:11:31:04 +0100] [Job 267] Job claims to be DSC-conforming, but "%%BeginProlog" was missing before first line with another "%%Begin..." comment (is this a TeX/LaTeX/dvips-generated PostScript file?). Assuming start of "Prolog" here.
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] -----------
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginProlog
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%EndProlog
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] -----------
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginSetup
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *Option1 None
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: Option1=None --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *Option20 False
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: Option20=False --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *Option25 False
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: Option25=False --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *Option30 None
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: Option30=None --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *RIPaperPolicy PromptUser
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: RIPaperPolicy=PromptUser --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *PageRegion A4
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: PageRegion=A4 --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *InputSlot 1Tray
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: InputSlot=1Tray --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *RPSBitsPerPixel 2BitsPerPixel
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: RPSBitsPerPixel=2BitsPerPixel --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *RIPrintMode 0rhit
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: RIPrintMode=0rhit --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *Duplex DuplexNoTumble
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: Duplex=DuplexNoTumble --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *ColorModel CMYK
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: ColorModel=CMYK --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *RPSRGBcorrect DetailBright
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: RPSRGBcorrect=DetailBright --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *RPSColorRendDict Auto
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: RPSColorRendDict=Auto --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *RPSDitherType Auto
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: RPSDitherType=Auto --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *RPSBlackMode gray
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: RPSBlackMode=gray --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *RPSBlackOverPrint False
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: RPSBlackOverPrint=False --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *RPSColorSep None
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: RPSColorSep=None --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *Rcmyksimulation Off
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: Rcmyksimulation=Off --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *Rimagesm Off
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: Rimagesm=Off --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *RIOrientOvr Off
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: RIOrientOvr=Off --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *Collate False
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: Collate=False --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *MediaType Auto
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: MediaType=Auto --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *OutputBin Default
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: OutputBin=Default --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *StapleLocation None
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: StapleLocation=None --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *RIPunch None
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: RIPunch=None --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *JobType Normal
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: JobType=Normal --> Setting option
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %% FoomaticRIPOptionSetting: JobType=Normal
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: JobType=Normal --> Setting option
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *LockedPrintPassword None
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: LockedPrintPassword=NoneThe value None for LockedPrintPassword is a predefined choice
D [25/Mar/2009:11:31:04 +0100] [Job 267] --> Setting option
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *DocServerPassword None
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: DocServerPassword=NoneThe value None for DocServerPassword is a predefined choice
D [25/Mar/2009:11:31:04 +0100] [Job 267] --> Setting option
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *UserCode None
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: UserCode=NoneThe value None for UserCode is a predefined choice
D [25/Mar/2009:11:31:04 +0100] [Job 267] --> Setting option
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *RIWatermark Off
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: RIWatermark=Off --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *RIWMText Confidential
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: RIWMText=Confidential --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *RIwmFont HelveticaB
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: RIwmFont=HelveticaB --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *RIwmSize 36
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: RIwmSize=36 --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *RIwmAngle 45Deg
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: RIwmAngle=45Deg --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginFeature: *RIwmTextStyle Gray
D [25/Mar/2009:11:31:04 +0100] [Job 267] Option: RIwmTextStyle=Gray --> Option will be set by PostScript interpreter
D [25/Mar/2009:11:31:04 +0100] [Job 267] Before page loop - %%Page: 1 1
D [25/Mar/2009:11:31:04 +0100] [Job 267] Copying page 1...
D [25/Mar/2009:11:31:04 +0100] [Job 267] pagew = 571.0, pagel = 818.0
D [25/Mar/2009:11:31:04 +0100] [Job 267] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
D [25/Mar/2009:11:31:04 +0100] [Job 267] PageLeft = 12.0, PageRight = 583.0
D [25/Mar/2009:11:31:04 +0100] [Job 267] PageTop = 830.0, PageBottom = 12.0
D [25/Mar/2009:11:31:04 +0100] [Job 267] PageWidth = 595.0, PageLength = 842.0
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%EndSetup
D [25/Mar/2009:11:31:04 +0100] [Job 267] Inserting PostScript code for CUPS' page accounting
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] -----------
D [25/Mar/2009:11:31:04 +0100] [Job 267] New page:  1 1
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginPageSetup
D [25/Mar/2009:11:31:04 +0100] [Job 267] Inserting option code into "PageSetup" section.
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%EndPageSetup
D [25/Mar/2009:11:31:04 +0100] [Job 267] End of page header
D [25/Mar/2009:11:31:04 +0100] [Job 267] Stopping search for page header options
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: (for) 11.0278 Tj
D [25/Mar/2009:11:31:04 +0100] [Job 267] --> Output goes directly to the renderer now.
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] Starting renderer
D [25/Mar/2009:11:31:04 +0100] [Job 267] JCL: <job data>
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] renderer PID kid4=5711
D [25/Mar/2009:11:31:04 +0100] [Job 267] renderer command: printf "%%!PS-Adobe-3.0\n%%%% %%%%\nmark\n() () (20`date +%y%m%d%R | sed 's/://'`) {setuserinfo} stopped\ncleartomark\n"; cat;
D [25/Mar/2009:11:31:04 +0100] [Job 267] Starting process 5712: "printf "%%!PS-Adobe-3.0\n%%%% %%%%\nmark\n() () (20`date +%y%m%d%R | sed 's/://'`) {setuserinfo} sto..."
D [25/Mar/2009:11:31:04 +0100] [Job 267] Copying page 2...
D [25/Mar/2009:11:31:04 +0100] [Job 267] pagew = 571.0, pagel = 818.0
D [25/Mar/2009:11:31:04 +0100] [Job 267] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
D [25/Mar/2009:11:31:04 +0100] [Job 267] PageLeft = 12.0, PageRight = 583.0
D [25/Mar/2009:11:31:04 +0100] [Job 267] PageTop = 830.0, PageBottom = 12.0
D [25/Mar/2009:11:31:04 +0100] [Job 267] PageWidth = 595.0, PageLength = 842.0
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%PageTrailer
D [25/Mar/2009:11:31:04 +0100] [Job 267] --> Continue DSC parsing now.
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%Page: 2 2
D [25/Mar/2009:11:31:04 +0100] [Job 267] --> Continue DSC parsing now.
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] -----------
D [25/Mar/2009:11:31:04 +0100] [Job 267] New page:  2 2
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%Page: 2 2
D [25/Mar/2009:11:31:04 +0100] [Job 267] --> Output goes to the FIFO buffer now.
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginPageSetup
D [25/Mar/2009:11:31:04 +0100] [Job 267] Inserting option code into "PageSetup" section.
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%EndPageSetup
D [25/Mar/2009:11:31:04 +0100] [Job 267] End of page header
D [25/Mar/2009:11:31:04 +0100] [Job 267] Stopping search for page header options
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: (k) 4.8634 Tj
D [25/Mar/2009:11:31:04 +0100] [Job 267] --> Output goes directly to the renderer now.
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] Copying page 3...
D [25/Mar/2009:11:31:04 +0100] [Job 267] pagew = 571.0, pagel = 818.0
D [25/Mar/2009:11:31:04 +0100] [Job 267] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
D [25/Mar/2009:11:31:04 +0100] [Job 267] PageLeft = 12.0, PageRight = 583.0
D [25/Mar/2009:11:31:04 +0100] [Job 267] PageTop = 830.0, PageBottom = 12.0
D [25/Mar/2009:11:31:04 +0100] [Job 267] PageWidth = 595.0, PageLength = 842.0
D [25/Mar/2009:11:31:04 +0100] [Job 267] Copying page 4...
D [25/Mar/2009:11:31:04 +0100] [Job 267] pagew = 571.0, pagel = 818.0
D [25/Mar/2009:11:31:04 +0100] [Job 267] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
D [25/Mar/2009:11:31:04 +0100] [Job 267] PageLeft = 12.0, PageRight = 583.0
D [25/Mar/2009:11:31:04 +0100] [Job 267] PageTop = 830.0, PageBottom = 12.0
D [25/Mar/2009:11:31:04 +0100] [Job 267] PageWidth = 595.0, PageLength = 842.0
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%PageTrailer
D [25/Mar/2009:11:31:04 +0100] [Job 267] --> Continue DSC parsing now.
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%Page: 3 3
D [25/Mar/2009:11:31:04 +0100] [Job 267] --> Continue DSC parsing now.
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] -----------
-------------------Removed the entries for the pages 4-13-----------------------
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] -----------
D [25/Mar/2009:11:31:04 +0100] [Job 267] New page:  14 14
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%Page: 14 14
D [25/Mar/2009:11:31:04 +0100] [Job 267] --> Output goes to the FIFO buffer now.
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BeginPageSetup
D [25/Mar/2009:11:31:04 +0100] [Job 267] Inserting option code into "PageSetup" section.
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%EndPageSetup
D [25/Mar/2009:11:31:04 +0100] [Job 267] End of page header
D [25/Mar/2009:11:31:04 +0100] [Job 267] Stopping search for page header options
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: -424 TJm
D [25/Mar/2009:11:31:04 +0100] [Job 267] --> Output goes directly to the renderer now.
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%PageTrailer
D [25/Mar/2009:11:31:04 +0100] [Job 267] --> Continue DSC parsing now.
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%Trailer
D [25/Mar/2009:11:31:04 +0100] [Job 267] --> Continue DSC parsing now.
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%DocumentSuppliedResources:
D [25/Mar/2009:11:31:04 +0100] [Job 267] --> Continue DSC parsing now.
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%Pages: 14
D [25/Mar/2009:11:31:04 +0100] [Job 267] --> Continue DSC parsing now.
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%BoundingBox: 0 0 595 842
D [25/Mar/2009:11:31:04 +0100] [Job 267] --> Continue DSC parsing now.
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] Found: %%EOF
D [25/Mar/2009:11:31:04 +0100] [Job 267] --> Continue DSC parsing now.
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] Closing renderer
D [25/Mar/2009:11:31:04 +0100] [Job 267] Process 5712 ending: "printf "%%!PS-Adobe-3.0\n%%%% %%%%\nmark\n() () (20`date +%y%m%d%R | sed 's/://'`) {setuserinfo} sto..."
D [25/Mar/2009:11:31:04 +0100] [Job 267] tail process done writing data to STDOUT
D [25/Mar/2009:11:31:04 +0100] [Job 267] KID4 finished
D [25/Mar/2009:11:31:04 +0100] [Job 267] KID3 exited with status 0
D [25/Mar/2009:11:31:04 +0100] [Job 267] KID4 exited with status 0
D [25/Mar/2009:11:31:04 +0100] [Job 267] Renderer exit stat: 0
D [25/Mar/2009:11:31:04 +0100] [Job 267] KID3 finished
D [25/Mar/2009:11:31:04 +0100] [Job 267] Renderer process finished
D [25/Mar/2009:11:31:04 +0100] [Job 267]
D [25/Mar/2009:11:31:04 +0100] [Job 267] Closing foomatic-rip.
D [25/Mar/2009:11:31:04 +0100] [Job 267] 1 files to send in job...
D [25/Mar/2009:11:31:05 +0100] [Job 267] Connected to 131.180.4.61:443 (IPv4)...
D [25/Mar/2009:11:31:05 +0100] [Job 267] Getting supported attributes...
D [25/Mar/2009:11:35:24 +0100] [Job 267] Getting supported attributes...
D [25/Mar/2009:11:35:24 +0100] [Job 267] document-format-supported (1 values)
D [25/Mar/2009:11:35:24 +0100] [Job 267] printer-uri = "https://srv525.tudelft.net:443/printers/3mE-8D-0-2/.printer"
D [25/Mar/2009:11:35:24 +0100] [Job 267] requesting-user-name = "root"
D [25/Mar/2009:11:35:24 +0100] [Job 267] job-name = "2008 - Hart - Phys Rev B preprint - Generating Derivative Structures.pdf"
N [25/Mar/2009:11:37:34 +0100] [Job 267] Print file accepted - job ID 94.