CUPS job processing time

[John A. Murdie]

Mike Sweet wrote:
> John A. Murdie wrote:
> > ...
> > Incidentally, even with 'raw', I note that page_log still contains
> > page counts for Windows -submitted files. Is there a 'raw raw' which
> > will prevent even this examination of the input files? (We do page
> > counting with an SNMP-based backend wrapper somewhat like PyKota.)
>
> The backends log PAGE: messages for each copy they send when doing
> raw printing.

Of course - thank you.

>  > ...
> > It may be that much of the contribution to the CUPS processing time
> > is from the Netapp filer - but I'm wondering why CUPS should take 35
> > seconds to process a single page job - is this expected with our
> > overall hardware/software? - or could we knock 30 seconds off this
> > time with a little care in configuration? It doesn't seem very much
> > absolute time, but would be a large percentage, and would improve
> > matters psychologically for the users of our small desktop printers.
>
> If you are doing raw printing, that 35 seconds is probably the time
> it takes to send the print data to the printer, which then starts
> processing the job data.  You can time the submission and printing
> times from the debug log messages in error_log, but that's the only
> processing that is going on - copying to/from the spool directory.

Ah, no - the 35 seconds (fairly close average for a one page job) is the time taken here by the scheduler for a (Windows-submitted) job *before* it starts a backend. (A colleague and I remark that what we've seen of Windows PostScript is that it is often somewhat larger than, say, dvips(1) output.) I'd need a CUPS log analyser before I could reliably describe the overall situation.

The 35 seconds duration is the difference between the time written to /var/log/messages by cups-lpd as it finishes transferring a job from our Windows server - i.e. the time the CUPS scheduler receives a job - and the time logged by our backend wrapper as the scheduler starts it. There is an additional 20 seconds (for a small printer, as I've said) taken for the backend to send the data to the printer and for the single page fully to appear, assuming the printer does not need warming up. This latter time is quite reasonable, given electromechanical hardware is involved. It's the 35 seconds the scheduler takes that I have my eyes on.

The slowness is probably something to do with our environment, but I would like to know how long the CUPS scheduler *should* take per job for a system like ours - 285 everyday users of 40 or so printers, though about twenty of those are personal printers used by just one person! (Yes, the latter are the bane of a printer administrator's life, even with decent remote monitoring.)

John A. Murdie