Bug 689850 - ghostscript causes long delays in photo printing
Summary: ghostscript causes long delays in photo printing
Status: RESOLVED WORKSFORME
Alias: None
Product: Ghostscript
Classification: Unclassified
Component: Regression (show other bugs)
Version: 8.64
Hardware: PC Linux
: P4 normal
Assignee: Default assignee
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2008-05-18 17:12 UTC by Martin G Miller
Modified: 2009-10-25 17:07 UTC (History)
0 users

See Also:
Customer:
Word Size: ---


Attachments
Typical .jpg that creates long printing que (4.06 MB, image/jpeg)
2008-05-19 06:54 UTC, Martin G Miller
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Martin G Miller 2008-05-18 17:12:42 UTC
Ubuntu Hardy heron using ghostscript v. 8.61.dfsg.1-1ubuntu3.
photo printing 4 x 6 prints results in pictures sitting in the print que with gs
showing 88-95% cpu for 80-90 seconds before sending to printer.  8x10 prints can
sit in gs que for upwards of 5 minutes or more. Once the item is released by gs
and is allowed to pass to the printer driver (turboprint), it prints at normal
speed.  Printing regular text documents or simple graphics on plain paper pass
through ghostscript almost instantly.  Previous versions of gs as used in Ubuntu
7.04 had ghostscript que time at only 5-10 seconds for 4 x 6 photo printing. 
There was a cups problem associated with this that has been resolved since the
release of Ubuntu 8.04, however, the ghostscript bug remains.  A bug was filed
with Ubuntu on 10-25-2007, bug # 157044: 
https://bugs.launchpad.net/ubuntu/+source/ghostscript/+bug/157044  It remains
unresolved.
Comment 1 Alex Cherepanov 2008-05-18 18:16:16 UTC
Please attach a sample file that demonstrated the problem and
provide the command line you use.

If possible, try to reproduce the problem using a simple device such as TIFF or
PNM writer.
Comment 2 Martin G Miller 2008-05-19 06:54:02 UTC
Created attachment 4032 [details]
Typical .jpg that creates long printing que

Attached is a typical jpeg that will produce the printing delay.  It doesn't
matter what application I print from.  As soon as gs gets it, it's stuck for
80-90 seconds.	What is pnm writer? I thought tiff is an uncompressed graphics
format.  My camera produces .jpg's.  I have created .png's from scanned images
and the effect is the same delay when printing to photo paper.	If you give me
a command to print the file from command line, I will try it.  I always print
from eye of gnome, open office writer or picasa.
Comment 3 Martin G Miller 2008-05-19 07:06:32 UTC
I tried converting the .jpg that I just sent you to a .tiff using gthumb.  I
selected the default of "normal deflation" when saving the file, so it must
still have some compression.  It's size increased form 4.1 MB to 10.1 MB.  The
time it sat in the the gs que, dropped from 90 seconds to 30 seconds.  Is
ghostscript trying to uncompress the jpeg file before sending it to the printer
driver?  The old version of ghostscript as used in Ubuntu 7.04 and earlier never
held jpeg's in que for more than 5-10 seconds.
Comment 4 Martin G Miller 2008-05-19 07:19:18 UTC
I just converted the .tiff to .pnm with raw formatting using gimp.  The file
size increased to 17.5 MB and the time in gs que dropped to 25 seconds.  When I
converted the .tiff to .bmp using gimp the file size stayed the same at 17.5 MB
but the time in gs que increased to 55 seconds.
Comment 5 Ray Johnston 2008-05-22 09:34:25 UTC
On a debug build, my 2GHz Intel Core laptop, this JPEG can be converted to
ppmraw in 1.6 seconds parse time, 4.1 seconds total.

If I add -dUseCIEColor the time increases to 10.5 seconds.

The command line I used was:
gswin32c -dUseCIEColor -sDEVICE=ppmraw -o nul -r600 -Z: viewjpeg.ps -c
"(bug_689850.jpg) viewJPEG"

Note that output to a file (7200 rpm hd) slows the time down by about 12 sec.

The problem is probably some device driver that is doing really slow F-S
dithering,but this isn't a problem intrinsic to Ghostscript.
Comment 6 Martin G Miller 2008-05-22 14:07:16 UTC
This is still a regression.  I used to be able to simply print jpegs with no
more than 5-10 seconds delay.  It is now 80-90 seconds.  Your using a command
line print command to convert and do other things is not consistent with the
normal work flow of the average user.  The original jpeg is opened in some photo
editing application, whether it be fspot, gthumb, picassa, etc.  tweaks are done
and then the file is printed.  It is now so slow, it creates problems.  8 x 10
is unusable. How is some other device driver responsible if it's gs that sits in
top using all the cpu time and as soon as it releases it, the file prints almost
instantly?  Please try printing the file I sent you as a jpeg from a typical
photo printing application to photo paper (or at least what the driver thinks is
photo paper, if you don't want to use the good stuff).  I have been having this
problem for over a year now.  It really needs some further attention.
Comment 7 Martin G Miller 2008-05-22 16:03:29 UTC
The other thing I didn't make clear is what happens when you have more than one
print to do.  If I send 4 prints to the printer, gs spikes at 80+% cpu for 80-90
seconds, then sends it to the printer.  gs drops to essentially nothing while
the print is printing, after the printer is through, gs spikes again to 80+% for
another 80-90 seconds and the next print is sent to the printer.  This cycle
repeats for all the prints in the cue.  The old behavior was to have the prints
just print one after the other after a 5-10 second delay.   If I try to do 8 x
10, there is a 5+minute delay between each print.

The immediate previous version of ghostscript as used in Ubuntu 7.10 used to
spike the cpu to 99+% making the whole system bog down.  At least I have a
little overhead now, but it's still not right.

My hardware is AMD 64 3200+ with 2 gig ram and 7200 rpm SATA HDD. 

Please keep this bug open.
Comment 8 Ralph Giles 2008-05-22 16:19:52 UTC
If you're complaining about the duty cycle, I think that's a CUPS bug.

Can you extract a command line from the print system that reproduces the slow
output? Right now there's not enough information for us to be able to track down
the problem.
Comment 9 Ralph Giles 2008-05-22 17:53:19 UTC
More information: I tried printing the attached jpeg from 'eog' on hardy heron
(Ubuntu 8.04 on x86_64) to my HP Deskjet 990c, best quality on photo paper. A
23MB spool file, Postscript level 3 created by cairo was placed in the print queue.

Foomatic-gswrapper called ghostscript with the following command line:

gs -sstdout=%stderr -dBATCH -dPARANOIDSAFER -dQUIET -dNOPAUSE -sDEVICE=ijs
-sIjsServer=hpijs -sDeviceManufacturer=HEWLETT-PACKARD -sDeviceModel=DESKJET 990
-dDEVICEWIDTHPOINTS=612 -dDEVICEHEIGHTPOINTS=792 -dDuplex=false -r600
-sIjsParams=Quality:Quality=2,Quality:ColorMode=2,Quality:MediaType=2,Quality:PenSet=2,PS:MediaPosition=7
-dIjsUseOutputFD -sOutputFile=%stdout -_

Printing began after a few seconds. Ghostscript (and hplip) used a few % cpu
while the print job was active, which is normal for this printer.

You can get the gs command line by typing 'ps aux | grep gs' (or grep lp) in a
terminal window while it's running the job.

In short, we still cannot reproduce and don't know how to resolve the regression
for you with what you've given. I'm surprised the input file format makes a
difference, as you describe in #3. In normal printing workflow, the application
generates a postscript file which it hands to CUPS. CUPS then does some
processing on the file, then either sends it directly to the printer, or uses
ghostscript to rasterize the file. The raster output is either fed directly to a
printer driver (as in the example with an HP printer above) or spooled and then
sent in a separate step, as with ppm2foo style drivers.

Neither generating postscript from an image, nor rasterizing it with Ghostscript
should take 5 minutes for this size of file. That's the origin of Ray's
suggestion in #5.
Comment 10 Ray Johnston 2008-05-22 18:32:14 UTC
From Ralph's testing,  I still don't have any information that leads me to
think that this is something in Ghostscript.

Obvipously, the submitter knows how to re-open the bug if information can be
provided that shows that the problem is in Ghostscript (as opposed to cups,
some other processing step, or a Ghostscript device driver).

It would help if the submitter can identify the device driver (target printer).
Comment 11 Martin G Miller 2008-05-22 19:44:35 UTC
I have tried printing to my Canon i960 while running the command you suggested.

The first few times I ran it, the prints started within 10 seconds of hitting
the print que.  This was very surprising behavior as I had just finished a print
run earlier this evening that behaved as I have described previously.  I then
rebooted the computer and reprinted the same image with the command as you
suggested.  This time it was in que for 50 seconds.  The output of the commad is
quite different before and after the boot.

First is before the boot with a ten second print que:
marty@tux:~$ ps aux | grep gs
marty     6425  0.0  0.7 171532 15216 ?        Sl   May14   1:22
gnome-settings-daemon
lp       16467  1.0  0.0   4388  1404 ?        S    21:57   0:00 i960_4x6_photo
658 marty (stdin) 1 media=4x6inBorderless sides=one-sided finishings=3
number-up=1 cpi=10 lpi=6 Resolution=600x600dpi_2
job-uuid=urn:uuid:990f382b-2bf8-3547-718e-a0a39c4d9f30 /var/spool/cups/d00658-001
lp       16469  0.0  0.0   4552  1744 ?        S    21:57   0:00 /bin/bash
/usr/lib/cups/filter/pstoturboprint 658 marty (stdin) 1 media=4x6inBorderless
sides=one-sided finishings=3 number-up=1 cpi=10 lpi=6 Resolution=600x600dpi_2
job-uuid=urn:uuid:990f382b-2bf8-3547-718e-a0a39c4d9f30
lp       16471  0.0  0.0   4324  1008 ?        S    21:57   0:00
usb://Canon/i960 658 marty (stdin) 1 media=4x6inBorderless sides=one-sided
finishings=3 number-up=1 cpi=10 lpi=6 Resolution=600x600dpi_2
job-uuid=urn:uuid:990f382b-2bf8-3547-718e-a0a39c4d9f30
lp       16487 81.0  0.6  24844 12600 ?        R    21:57   0:06 gs
-sDEVICE=pcx24b -r600x600 -g2518x3766 -dSAFER -dNOPAUSE -dBATCH
-sOutputFile=/tmp/pstoturboprint16469.fifo -
marty    16491  0.0  0.0   3008   780 pts/0    R+   21:57   0:00 grep gs
marty@tux:~$ 


Next, after a reboot, the same image with a 50 second print que:

marty@tux:~$ ps aux | grep gs
marty     6462  0.1  0.6  43292 13884 ?        Sl   22:12   0:00
gnome-settings-daemon
lp        6847 85.3  0.5  24784 12452 ?        R    22:21   0:29 gs
-sDEVICE=pcx24b -r600x600 -g2518x3766 -dSAFER -dNOPAUSE -dBATCH
-sOutputFile=/tmp/pstoturboprint6829.fifo -
marty     6851  0.0  0.0   3004   752 pts/0    R+   22:22   0:00 grep gs
marty@tux:~$ 


If there is anything else I can do to help, please tell me.
Comment 12 Ray Johnston 2008-08-21 14:37:54 UTC
Since we can't reproduce this and it is non-deterministic, closing as INVALID
(assuming it is a problem on the user's system).
Comment 13 Antal Kovacs 2009-10-25 06:39:26 UTC
Bug is not solved, still the same behavior as reported by the report-opener. My
System:

Ubuntu 9.04 Jaunty
Linux 2.6.28
CUPS 1.3.9-17
Turboprint 2.11-2
HP OfficeJet Pro K550DTN
Intel Dual Core mit 3GHz
2GB Ram
Comment 14 Ray Johnston 2009-10-25 17:07:14 UTC
Ghostscript latest release is 8.70 and this bug will be closed as invalid
until the user tests with that version.

Also note that we need the PostScript file created by cups, NOT the original
JPEG file to determine if the problem is a change in Ghostscript or in CUPS.

My testing with older versions shows that with gs8.61 vs. 8.70 using the EXACT
command line:

time gswin32c -Ilib -Z: -sDEVICE=pcx24b -o x.pcx -r600x600 -g2518x3766 \
  lib/viewjpeg.ps -c "(/artifex/bugs/bug-gs/bug_689850.jpg) viewJPEG \
  showpage quit"

the results in seconds on my 2 GHz Core 2 with 2Gb RAM are :

         gs8.61    gs8.70    HEAD(rev 10208)
real      13.9       9.8       9.8         
user      12.8       8.8       8.8

Please do not reopen this bug until a PostScript file can be produced which
shows a difference, posted with a Ghostscript command line that shows the
timing differences are due to Ghostscipt we will assume that the problem is
in CUPS or a particular driver (such as the "HP IJS" driver mentioned in the 
initial report, rather than the pcx24b that is present in the GS sources).