Too many copies #1184

Closed
michaelrsweet opened this Issue May 17, 2005 · 16 comments

Comments

Projects
None yet
1 participant
Collaborator

michaelrsweet commented May 17, 2005

Version: 1.1.20
CUPS.org User: kssingvo.suse

Regarding STR #1043: [ http://www.cups.org/str.php?L1043 ]
We (SUSE) noticed this problem either.

But to our knowledge it happens only, if small (!) files (like ASCII documents, e.g. "/etc/motd") are sent to a (broadcasting/browsing) server and then printed on a fast PS capable printer (HP LaserJet 4300 dtn).

IIRC: The problem seems to be in the communication: the client creates the job several for the server. This comes from a response the server, where he is telling the client that the job is not printed and therefore the client is transmitting the job again and again and again.

The cups server runs with cups-1.1.20
The cups client runs with cups-1.1.23

I didn't debug this (yet). All I can say that we noticed this problem, with ASCII text documents only; long files especially PS file seem to be printed flawless.

For the sake of completeness :-) I attached the error_log from the client. Please note that I had to stop the cupsd, because he printed the motd around 60 times without stopping.

Collaborator

michaelrsweet commented May 24, 2005

CUPS.org User: kssingvo.suse

I compiled cups/ipp.c with DEBUG enabled, to get more information. :-)

But as this issue happens only on our production machine, I could not replace the library during work hours and it took some time to wait for a good and not so noisy chance. :-)

I attached the server logfile with debug output: the same job got printed by the printer, but the server returned an (invalid) error message to the client, therefore the client sent the job again, got again printed by the server, but reproduced the (invalid) error from to client again, etc.

I stopped it after the 3rd (and unwished) printout copy.

Hopefully someone understands the protocoll so far and can give me a hint where cups-1.1.20 (!) has it problem.

Collaborator

michaelrsweet commented May 25, 2005

CUPS.org User: kssingvo.suse

I continued debugging...

Now it looks like this:
during the client <-> server communication the server reads some data from the client, but after a while the daemon returns IPP_ERROR in this function:

cups/ipp.c:
ippReadIO(...)
[...]
switch (ipp->state) {
[...]
case IPP_HEADER :
[...]
if ((n = (*cb)(src, buffer, 8)) < 8) {
DEBUG_printf(("ippReadIO: Unable to read header (%d bytes read)!\n", n));
return (n == 0 ? IPP_IDLE : IPP_ERROR);
}

According to my debug-information: the daemon receives via ipp_read_http() call -1 bytes and the errno is set to 4 (= EINTR).

So I assume that here the printer backend is sending a signal to the daemon, about its finished communication to the printer (as it happens only with small jobs on fast printers, I interpret this as a valid theory).

So, whoever is familiar with code (hello Michael :-), can you tell me which signal handlers are playing role in this case?

Have you any patch for above case handy, like mapping errno=4 to IPP_IDLE in the return case too?

Collaborator

michaelrsweet commented May 25, 2005

CUPS.org User: mike

OK, it looks like httpRead() is not retrying on EINTR or EAGAIN, which is ultimately causing the problem. ipp_http_read() is getting 0 bytes and breaks out of the loop early, causing the IPP_ERROR return...

I'll have a patch for you later today...

Collaborator

michaelrsweet commented May 25, 2005

CUPS.org User: mike

Oh, and BTW thanks for doing all of that testing - this has been a long-standing issue and we were never able to reproduce the problem in our lab!

Collaborator

michaelrsweet commented May 25, 2005

CUPS.org User: mike

Fixed in Subversion repository.

Try the attached patch and let me know...

Collaborator

michaelrsweet commented May 27, 2005

CUPS.org User: jsousa

I am getting this problem consistently.

Printing n>1 copies of documents always result in n*n printouts. This occurs consistently on macosx (10.3 and 10.4) and linux debian (cups 1.1.23). XP/2000 seems not to be affected by this issue.

Printing the copies collated or not has no influence.

The setup is as follows:

clients (cups and drivers)
-> debian CUPS queue server
-> PS printers (HP4250DN and HP4100N).

Linux printing from KDE applications causes this issue, but open office seems not to cause it.

Macosx allways causes this issue, from powerpoint, word or safari.

I applied the above mentioned patch to the debian source package (cupsys 1.1.23) and it did not solve any of the above issues.

Collaborator

michaelrsweet commented May 27, 2005

CUPS.org User: mike

Joao,

Your problem is unrelated to this, but is a bug in the KDE PostScript output and/or the driver you are using.

Collaborator

michaelrsweet commented May 27, 2005

CUPS.org User: jsousa

You are right in saying that the linux printing issue could be a kde but, but that does not explain the identical symptoms that occur in the macosx workstations.

I was guessing that what KDE is doing would be similar to what macosx was doing.

Unfortunately, I'm a a simple user of cups, macosx and kde, so I am unable to do a more profound analysis of the issue.

Collaborator

michaelrsweet commented May 30, 2005

CUPS.org User: kssingvo.suse

I'm sorry to say, but Michael's patch doesn't work [Note: you might remove it in Subversion repository].

Therefore I digged deeper into this problem and noticed this after a while:
cups/ipp.c:ipp_read_http() returned -1 and caused the problem in cups/ipp.c:ippReadIO()

Having a closer look at ipp_read_http(), the -1 is coming from evaluation of call: !httpWait(http, 1000) /* Signal no data... */

I assume now that the EINTR might be caused by a non-blocked SIGALARM, which is enabled by the scheduler somewhere else and triggered by the httpWait (= select()) call

Therefore I thought, I should change in cups/ipp.c:ippReadIO() the evaluation of
if ((n = (*cb)(src, buffer, 8)) < 8) {
[...]
return (n == 0 ? IPP_IDLE : IPP_ERROR);
}

I don't know, if this is correct, but an additional "return(IPP_IDLE);" in case of "n == -1 && errno == EINTR" seems to solve the problem. (I'll post patch RSN).

Michael: I appreciate any comments from you, if I understood the state machine of your scheduler right and if my patch is valid or will break anything else. Thanks in advance.

Collaborator

michaelrsweet commented May 31, 2005

CUPS.org User: kssingvo.suse

Another possibility to solve this issue (but not tested in reality by me):

In cups/ipp.c:ipp_read_http()
After the "httpWait(http, 1000)" returns 0 (= signal, but no data), remove the "bytes = -1;" assignment, because the timeout occurred, means the SIGALARM was sent.

But this decision has to be done by someone who is more familiar with the code and its state machine. As it affects the libcups, any such chance might have also influence on other applications, like samba, kde-print, hplip, etc.

Collaborator

michaelrsweet commented May 31, 2005

CUPS.org User: mike

http_wait() (which is called by httpWait()) checks for EINTR and retries as needed, which was added to fix STR #1020. This fix was included in 1.1.23rc1...

The STR is against 1.1.20 - is that the version you are testing with, or the current stable 1.1.23 release?

Collaborator

michaelrsweet commented Jun 1, 2005

CUPS.org User: kssingvo.suse

Sorry to say, but I can only reproduce this issue with a certain hardware configuration (I tried it with my test-machines, but it doesn't occur).
The server, where I'm able to reproduce this problem, needs to a run a specific SUSE version w/o modifications. Therefore I can only test cups-1.1.20.

Collaborator

michaelrsweet commented Jun 1, 2005

CUPS.org User: mike

STR #1020 also has an attached patch you can try against 1.1.20:

http://www.cups.org/str.php?L1020
Collaborator

michaelrsweet commented Jun 1, 2005

CUPS.org User: kssingvo.suse

Yes, patch from STR#1120 fixes the problem.

Collaborator

michaelrsweet commented Jun 1, 2005

"str1184.patch":

Index: http.c

--- http.c (revision 4515)
+++ http.c (working copy)
@@ -1,5 +1,5 @@
/*

  • * "$Id: http.c,v 1.144 2005/01/03 19:29:45 mike Exp $"

    • "$Id$"
      *
    • HTTP routines for the Common UNIX Printing System (CUPS).

    @@ -1012,7 +1012,11 @@
    return (0);

    DEBUG_printf(("httpRead: reading %d bytes from socket...\n", length));

  • bytes = recv(http->fd, buffer, length, 0);

  • while ((bytes = recv(http->fd, buffer, length, 0)) < 0)
  •  if (errno != EINTR)
    
  •    break;
    
    DEBUG_printf(("httpRead: read %d bytes from socket...\n", bytes));
    }

@@ -2557,5 +2561,5 @@

/*

  • * End of "$Id: http.c,v 1.144 2005/01/03 19:29:45 mike Exp $".
  • * End of "$Id$".
    */
Collaborator

michaelrsweet commented Jun 1, 2005

"cups-1.1.20-multiple_pages.patch":

--- cups-1.1.20/cups/ipp.c.orig 2005-05-30 20:06:54.000000000 +0200
+++ cups-1.1.20/cups/ipp.c 2005-05-30 20:12:27.000000000 +0200
@@ -895,6 +895,8 @@
if ((n = (*cb)(src, buffer, 8)) < 8)
{
DEBUG_printf(("ippReadIO: Unable to read header (%d bytes read)!\n", n));

  •   if (n == -1 && errno == EINTR)
    
  •     return (IPP_IDLE);
    return (n == 0 ? IPP_IDLE : IPP_ERROR);
    
    }

michaelrsweet added this to the Stable milestone Mar 17, 2016

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment