Description of problem: When a user want to print n copies of a ps file, unexpectedly get n*n copies. When n will be greater,printed then very huge number of copies. And all of this copies means a loss of resources and time. We have a prepaid printing system for students and this problem is very annoying for us. Therefore i pick up the severity high. Version-Release number of selected component (if applicable): cups-1.2.4-11.18.el5_2.3 How reproducible: Pick up a ps file and give a number for copies greater then 1 . lp -n 2 file.ps Actual results: 2 * 2 copies of print job. Expected results: Only 2 copies of print job. Additional info: This problem is reported also in bug tracking system of ubuntu (See external bug) and seems to have been fixed.
Please attach the PPD for this printer (from /etc/cups/ppd/$queuename.ppd), as well as an example PostScript job that triggers the problem.
Created attachment 327758 [details] HP-LaserJet_4350-hpijs.ppd obtained from linuxprinting.org Requested ppd file
Created attachment 327759 [details] A PS file I can reproduce the problem with any ps file, even so a attached an example file.
Apologies for the time taken to analyse this. I just tried this with 'lp -n3 printing_test.ps' and got 6 pages written to the printer, which would have resulted in the expected 3 sheets presuming a duplex unit is connected. The Ubuntu bug report you reference is about a problem in Ubuntu-specific print filters not shipped in Red Hat Enterprise Linux 4, and so this is not relevant to the issue. I would very much like to see debugging output if that's possible. Here is how: 1. Edit /etc/cups/cupsd.conf and find the line that begins 'LogLevel'. Change that line to read 'LogLevel debug2'. 2. Run '/sbin/service cups restartlog' (this will clear out any existing /var/log/cups/error_log file). 3. Run your test case, selecting '3' (not '2') as the number of copies. 4. Finally, please attach the /var/log/cups/error_log file to this bug report. Thanks.
(In reply to comment #4) > Apologies for the time taken to analyse this. > > I just tried this with 'lp -n3 printing_test.ps' and got 6 pages written to the > printer, which would have resulted in the expected 3 sheets presuming a duplex > unit is connected. > The unit is duplex capable, but the pages printed single sided in our case. > The Ubuntu bug report you reference is about a problem in Ubuntu-specific print > filters not shipped in Red Hat Enterprise Linux 4, and so this is not relevant > to the issue. Ok. :) > I would very much like to see debugging output if that's possible. Here is > how: > > 1. Edit /etc/cups/cupsd.conf and find the line that begins 'LogLevel'. Change > that line to read 'LogLevel debug2'. This was already so. > 2. Run '/sbin/service cups restartlog' (this will clear out any existing > /var/log/cups/error_log file). This do i not, because ... > 3. Run your test case, selecting '3' (not '2') as the number of copies. > > 4. Finally, please attach the /var/log/cups/error_log file to this bug report. No error output trigged when the pages printed. Neither in error_log nor in acces_log. By the way, we have updated cups to version 1.3.7 . But the problem is already present. P.S.: If i try to print pages over a Print-Dialog(GUI), the pages printed correctly. Sorry for late answer. Cheers, Selim
And an additional note: This problem is not a printer specific configuration or something else problem, because our color printer has a completely different ppd and it's kyocera. And this printer shows the same issue. :(
The pstops provided in cups 1.2.x had a number of problems at least one of which sounds very much like this which is why we were forced to switch to cups-1.3 a long time ago. I note that RH now ship a cups-1.3 for rhel5 so if you havn't already updated to that it would be well worth doing. Apart from that I can only think that there may be some interaction between the cups server and clients each performing a multiplication effect - e.g. the sl5 evince does this for us https://bugzilla.redhat.com/show_bug.cgi?id=439937 (possibly because the evince authors were trying to work round a different bug), so we have to use a patched evince on our el5 machines... BTW when we reported a bug with MATLAB r2008a/b not being able to talk properly to cups-1.3 servers their response was to downgrade to cups-1.2 (ha!) but in fact just switching to a newer Sun JRE fixes it... -- Jon
In reply to #5 the logs really ought to contain at least a few lines. We normally run with LogLevel debug and our access and error logs can get quite big (with a few hundered client machines). Do you at least get something to the page_log? Can you check that you have reloaded cups after changing the log-level? Do you have anything odd (or non-standard) in the /etc/cups/mime.convs file or cupsd.conf files?
Created attachment 338507 [details] Cups error log after n*n problem (In reply to comment #5) > > 4. Finally, please attach the /var/log/cups/error_log file to this bug report. > > No error output trigged when the pages printed. Neither in error_log nor in > acces_log. Hi, Sorry for inconvenience, yesterday i can't get any log output, but today i can. I attached the log file. (In reply to comment #8) > Do you have anything odd (or non-standard) in the /etc/cups/mime.convs file or > cupsd.conf files? No.
There is a new experiment: I have created a samba shared printer on a win server and include it as a new printer in cups. In fact it's the same printer which i reproduce the problem with cups and all the processing of the print job run on CUPS server. Also pstops and then hpijs processed the job and forward it to win print server. If i send the job over samba the problem does not occur and i get 3 pages as expected. If i send the job normally without samba the problem occurs. Also the client is the same. Spooler is the same also CUPS. Driver is the same also HPIJS. Transfer way is different. SAMBA or direct. Printer is the same. So i think the problem occurs somewhere in the transport way. Any suggestions? P.S.: I also experimented with different PPD's, Postscript PDD and HP PPD from Foomatic. The problem exists on both.
On the end i have a possible analyze of this problem. So i have read somewhere that the pstops filter included the number of the copies of the pages in the ps file during the filtering phase. And the IPP protocol send the number of copies also to the printer. Finally the printer get a ps file which included the information of the number of copies and seperately number of copies of current print job from IPP. So every copy of the job printed with the same number of copies over again. So this explain why the problem over SAMBA printing not occurs. And after all this analysis i have experiented the print command with -oraw *parameter and with this parameter the problem does not occurs. *Definition of -oraw : The -o raw option allows you to send files directly to a printer without filtering.
Yet another information: I have a pdf file which i can reproduce the same problem. Also with -oraw parameter or over SAMBA share the problem does not occur. I'll attach this pdf file here, if i can get the authorization of its owner. Reminding: Not all pdf files cause this problem.
Are you sending the job to the printer using ipp? I ask because in general (ie normally) only the last ipp spooler actually does the filtering, but you are using a PPD which has some magic cupsFilter lines in it so I'm not sure where it will happen. As a random data point we always set up our HP printers so that the cups server sends the data to them over the appsocket interface (ie using socket URIs in the cups config), and we use the PPDs downloaded from linuxprinting.org but NOT the HPIJS ones... To quote from the middle of the PPD you posted: *driverName hpijs/hpijs - HP's IJS driver for most of their non-PostScript printers: "" But the HP laserjet 4350 is a postscript printer so you don't need to run the job through foomatic to convert from postscript. ie for the 4350 we use: http://www.linuxprinting.org/foomatic-db/db/source/PPD/HP/HP_LaserJet_4350.ppd though we do also tweak it a little. This may *not* be the cause of the extra page duplication but it probably won't be helping the performance or ability of cups to know about and drive printer features (such as duplex). The reason why -oraw is behaving differently is that it bypasses much of the cups filtering - sometimes this is what is needed from windows boxes but it can also cause more confusion. Here is an entry from /etc/cups/printers.conf for one of our HP 43509 printers: <Printer magpie> Info DAMTP; magpie - lj4350 duplex,tray3 Location PavB 1st floor North DeviceURI socket://lj4350n1.private.damtp.cam.ac.uk:9100 State Idle StateTime 1239198649 Accepting Yes Shared Yes JobSheets none none QuotaPeriod 0 PageLimit 0 KLimit 0 OpPolicy default ErrorPolicy retry-job </Printer> and all the non-default ppd settings were made by using lpadmin to set the following options: HPOption_Duplexer=True HPOption_Tray3=Tray3_500 InstalledMemory=Mem96_127 Duplex=DuplexNoTumble (we have a script which does that based on the printer features, I could send you the entire printer definition for this printer but it wouldn't mean anything to anyone who isn't using the same admin script)... Oh btw I see from the error log that cups filters are being run with the following arguments (argv counting from 0 which is the printer-name): D [07/Apr/2009:15:36:39 +0200] [Job 156586] argv[0]="i08pr-sw2-cups" D [07/Apr/2009:15:36:39 +0200] [Job 156586] argv[1]="156586" D [07/Apr/2009:15:36:39 +0200] [Job 156586] argv[2]="s_ok" D [07/Apr/2009:15:36:39 +0200] [Job 156586] argv[3]="printing_test.ps" D [07/Apr/2009:15:36:39 +0200] [Job 156586] argv[4]="3" D [07/Apr/2009:15:36:39 +0200] [Job 156586] argv[5]="media=A4 sides=two-sided-long-edge finishings=3 number-up=1 job-uuid=urn:uuid:95b8a7da-3ded-3ece-5f1e-9a3cac0061bf" D [07/Apr/2009:15:36:39 +0200] [Job 156586] argv[6]="/var/spool/cups/d156586-001" argv[4] is the number of copies (3 as expected), but there is also the option finishings=3 being passed which I've never noticed here. Maybe it is for the HPIJS code or maybe it is something new. -- Jon
(In reply to comment #13) > Are you sending the job to the printer using ipp? I ask because in > general (ie normally) only the last ipp spooler actually does the > filtering, but you are using a PPD which has some magic cupsFilter > lines in it so I'm not sure where it will happen. Yes, we are using ipp. As i explained before, this problem occurs only with the combination of using the filters and ipp. > As a random data point we always set up our HP printers so that the > cups server sends the data to them over the appsocket interface (ie > using socket URIs in the cups config), and we use the PPDs downloaded > from linuxprinting.org but NOT the HPIJS ones... > > To quote from the middle of the PPD you posted: > > *driverName hpijs/hpijs - HP's IJS driver for most of their non-PostScript > printers: "" > > But the HP laserjet 4350 is a postscript printer so you don't need to > run the job through foomatic to convert from postscript. ie for the > 4350 we use: We are using HPIJS , because when we use PPDs without HPIJS some pdf files cause to service error on the printer and this can we fix only by shutting down and restart the printer. > > This may *not* be the cause of the extra page duplication but it > probably won't be helping the performance or ability of cups to know > about and drive printer features (such as duplex). > > The reason why -oraw is behaving differently is that it bypasses much > of the cups filtering - sometimes this is what is needed from windows > boxes but it can also cause more confusion. > > Here is an entry from /etc/cups/printers.conf for one of our HP 43509 printers: > > <Printer magpie> > Info DAMTP; magpie - lj4350 duplex,tray3 > Location PavB 1st floor North > DeviceURI socket://lj4350n1.private.damtp.cam.ac.uk:9100 > State Idle > StateTime 1239198649 > Accepting Yes > Shared Yes > JobSheets none none > QuotaPeriod 0 > PageLimit 0 > KLimit 0 > OpPolicy default > ErrorPolicy retry-job > </Printer> > > and all the non-default ppd settings were made by using lpadmin to set > the following options: > > HPOption_Duplexer=True > HPOption_Tray3=Tray3_500 > InstalledMemory=Mem96_127 > Duplex=DuplexNoTumble > > (we have a script which does that based on the printer features, I > could send you the entire printer definition for this printer but it > wouldn't mean anything to anyone who isn't using the same admin > script)... > > Oh btw I see from the error log that cups filters are being run with > the following arguments (argv counting from 0 which is the > printer-name): > > D [07/Apr/2009:15:36:39 +0200] [Job 156586] argv[0]="i08pr-sw2-cups" > D [07/Apr/2009:15:36:39 +0200] [Job 156586] argv[1]="156586" > D [07/Apr/2009:15:36:39 +0200] [Job 156586] argv[2]="s_ok" > D [07/Apr/2009:15:36:39 +0200] [Job 156586] argv[3]="printing_test.ps" > D [07/Apr/2009:15:36:39 +0200] [Job 156586] argv[4]="3" > D [07/Apr/2009:15:36:39 +0200] [Job 156586] argv[5]="media=A4 > sides=two-sided-long-edge finishings=3 number-up=1 > job-uuid=urn:uuid:95b8a7da-3ded-3ece-5f1e-9a3cac0061bf" > D [07/Apr/2009:15:36:39 +0200] [Job 156586] > argv[6]="/var/spool/cups/d156586-001" > > argv[4] is the number of copies (3 as expected), but there is also the > option finishings=3 being passed which I've never noticed here. Maybe > it is for the HPIJS code or maybe it is something new. This arguments are probably defined after the filters processed the job. Why this happen i don't know. But i'm clarly sure, that the pstops filter include some copie information on the processed data and ipp include it also and than we get squared number of document.
(In reply to comment #14) > (In reply to comment #13) > > Are you sending the job to the printer using ipp? I ask because in > > general (ie normally) only the last ipp spooler actually does the > > filtering, but you are using a PPD which has some magic cupsFilter > > lines in it so I'm not sure where it will happen. > > Yes, we are using ipp. As i explained before, this problem occurs > only with the combination of using the filters and ipp. Ok, if sending the job via socket:// URIs works then is there a good reason not to use that? ... > > But the HP laserjet 4350 is a postscript printer so you don't need to > > run the job through foomatic to convert from postscript. ie for the > > 4350 we use: > > We are using HPIJS , because when we use PPDs without HPIJS some pdf > files cause to service error on the printer and this can we fix only > by shutting down and restart the printer. Fair enough - we find that the latest HP firmware does help a lot (that being 08.015.0 for the 4350 from May 2008), but they still occasionally crash when processing some documents. We found that adding more memory to the printers made the problem happen less often... I suspect that since the 4350 is no longer current HP may not bother fixing it further... Normally the only filter processing is done by the last IPP spooler (the one nearest the printer!) so the HPIJS filtering is probably not well tested for cases when the document is then delivered to the printer by IPP which may well implement/obey some of the IPP options itself... I don't think this is a bug in cups itself, though I suppose one could argue that it is a bug in the HPIJS mechanisms... -- Jon
I asked the question about the socket protocol to my forerunner and he sad : we just pick up the ipp. So i can test it in the near future with sockets. And the other highlights are: - The problem occurs also with Postscript PPDs. - The finishings parameter indicate always 3, also no relationship with numbers of copies.
The finishings parameter just means "no special finishings". I think these two CUPS bug reports are related, although not quite the same as this bug report: http://cups.org/str.php?L2349 http://cups.org/str.php?L2518 From the error_log you've attached I can see that the handling of multiple copies is performed both by pstops and by the ipp backend, which creates three jobs on the remote device. Reading through STR #2349 the intended behaviour seems to be that the ipp backend should not send multiple copies when printing filtered output, so this seems to be a CUPS bug. However, I can't see where the bug is, looking at the source code. Can you please confirm the name-version-release you are using of cups, with 'rpm -q cups'? That way I know I'm looking at the source code of the same package.
Today i have realize that we use an another backend for the accounting accsnmp. If i set the configuration without the accsnmp backend, i get no problem. IPP as well as Socket protocol cause no problems. So the problem occurs due to buggy accsnmp backend, which not shipped with original cups package. This means, this bug is invalid. There is a new version of accsnmp that we should to try it. In the changelog mentioned about a bug fix related with the copies argument. Sorry due to inconvenience.
OK, thanks for investigating.