Bug#682426: Further test results
In an effort to further isolate causes of
my print hangs, I ran a print job without first
shutting down either firefox or chromium processes.
I thought if the job would run reasonably with
a low amount of free (real) RAM it might make a
stronger case for the 'default-pdftops-renderer'
fix (set it to pdftops) being a silver bullet.
A word here about how I print: I use
firefox to print but due to some margin issues
and not being able to see the page number on the top
or bottom when printing from the browser, I print to
a pdf file, which includes the header and footer
I have set in the firefox settings. I then open
the pdf document in evince and print to the printer.
The job I printed today completed in reasonable
time with ~30M free RAM, with about 19 and 28M in
buffers and cached respectively (~330+M free RAM).
The file (mozilla0.pdf) has size 129578 bytes,
it is a 14 page article. Firefox was open with about 28 tabs open,
and there were about 10 chromium tabs/processes open.
This was about the load I had when the problem started
manifesting itself and before setting default-pdftops-renderer.
So the good news is I think I can print without shutting down
multiple chrome processes and/or Iceweasel/Firefox.
The other news, while not bad, is confusing (to me).
I had turned on CUPS debugging to try and see what filter(s)
were being used, also to try and shed some light on internal
processing because I couldn't verify what the default pdftops
renderer was from 'lpoptions -p [printer name] -l'.
Monitoring of the processes via 'ps' during the print job
showed multiple CUPS spawned lp processes, with
'default-pdftops-renderer' set to 'pstopdf'! Perusal of
the CUPS error log confirmed this:
[Job 1299] argv[5]="InputSlot=Upper number-up=1 PageSize=Letter
MediaType=Automatic noOptionDuplex OutputMode=Normal ColorModel=RGB
Duplex=None job-uuid=urn:uuid:c4c474b9-6bbf-34a1-4d2f-ccbc86c7382d
pdftops-renderer=pstopdf job-originating-host-name=localhost
time-at-creation=1371837912 time-at-processing=1371837912"
Further down I see the following filters were invoked:
I [21/Jun/2013:14:05:13 -0400] [Job 1299] Started
filter /usr/lib/cups/filter/pdftopdf (PID 17520)
I [21/Jun/2013:14:05:13 -0400] [Job 1299] Started
filter /usr/lib/cups/filter/gstoraster (PID 17521)
I [21/Jun/2013:14:05:13 -0400] [Job 1299] Started
filter /usr/lib/cups/filter/hpcups (PID 17522)
I [21/Jun/2013:14:05:13 -0400] [Job 1299] Started
backend /usr/lib/cups/backend/hp (PID 17523)
Ghostscript was indeed executed during the print job, as seen
by 'top', and verified in system accounting log, but the memory
used and CPU numbers seems pretty reasonable:
1 2.37re 0.80cp 0avio 8354k gs
Also, we see pdftopdf and hpcups :
1 0.04re 0.00cp 0avio 3086k pdftopdf
1 2.42re 0.39cp 0avio 2670k hpcups
Hope this helps shed some light on the problem for those
who know more about the internals of PDF processing than
I do. I must confess I'm pretty confused about how the
whole thing is wired together, specifically how 'pstopdf'
and 'pdftopdf' got into the picture?
Reply to: