A delay of 6-7 minutes between submission and printing of a job..
Helge Blischke
h.blischke at acm.org
Wed Mar 25 05:30:01 PDT 2009
Emre Sururi wrote:
> 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.
>From your log, it seems that establishing the connection to the printer or
getting the attributes from the printer takes that long time. I'd suggest to trace the communication with the real printer.
Helge
More information about the cups
mailing list