Otdfbt

I've seen tons of posts asking this and similar questions on various forums, but no one seems to be able to provide a solution.

The basic problem goes like this:

Printing worked fine on [Insert Old Version of Linux Distro], but after updating to [Newer version of Linux Distro], there's now a [5,10,15] second delay between sending a file to the print cue and when the printer actually starts printing.

In my particular case, printing started immediately on Ubuntu 8.04, but after upgrading to 10.04, has a 10 second delay. I'm doing this on Ubuntu Server, printing with the lpr command, but the problem is present on 10.04 desktop as well. From what I've read, it also affects newer versions of MOST linux distros. Fedora, OpenSUSE, Arch, etc.

The printers are all network printers. Printing from Windows is also immediate. The light on the printer starts blinking immediately, but nothing comes out for 10-15 seconds.

Ubuntu 10.04 uses CUPS 1.4.3. I thought it might be a bug in CUPS, so I compiled CUPS 1.4.5 (latest stable) to replace Ubuntu's 1.4.3. But there's still a delay.

Any idea what might be causing this? Or a way to troubleshoot the problem to figure out what's causing it?

UPDATE: I set loglevel to debug and got about 660 lines of output in my log for a single job. The test file I sent took 10 seconds from the time it was added to the cue to when it came out.

I won't post the whole thing here (unless you really want it!), but here's the highlights:

The job is cued and a bunch of things happen in that same second. The last line for that second is:

D [28/Nov/2010:14:44:19 -0500]
 Discarding unused printer-state-changed event...

The next log line occurs a full 4 seconds later:

D [28/Nov/2010:14:44:23 -0500]
 [Job 3071] prtGeneralCurrentLocalization type is 0, expected 2!

So we have a 4 second delay here for some reason.

1 second latter we get:

D [28/Nov/2010:14:44:23 -0500] PID 15448 (/usr/lib/cups/filter/pdftoraster) exited with no errors.
D [28/Nov/2010:14:44:24 -0500] [Job 3071] Wrote 8192 bytes of print data...
D [28/Nov/2010:14:44:24 -0500] [Job 3071] Read 8192 bytes of print data...
I [28/Nov/2010:14:44:24 -0500] [Job 3071] Printing page 1, 57% complete...
I [28/Nov/2010:14:44:24 -0500] [Job 3071] Printing page 1, 59% complete...
D [28/Nov/2010:14:44:24 -0500] Discarding unused job-progress event...
D [28/Nov/2010:14:44:24 -0500] Discarding unused printer-state-changed event...
I [28/Nov/2010:14:44:24 -0500] [Job 3071] Printing page 1, 60% complete...

Which repeats until:

I [28/Nov/2010:14:44:26 -0500] [Job 3071] Printing page 1, 99% complete...
D [28/Nov/2010:14:44:26 -0500] Discarding unused job-progress event...
D [28/Nov/2010:14:44:26 -0500] Discarding unused printer-state-changed event...
I [28/Nov/2010:14:44:26 -0500] [Job 3071] Ready to print.

Then it goes on to:

D [28/Nov/2010:14:44:26 -0500] [Job 3071] Wrote 8192 bytes of print data...
D [28/Nov/2010:14:44:26 -0500] [Job 3071] Read 8192 bytes of print data...

Over and over again until:

D [28/Nov/2010:14:44:29 -0500] [Job 3071] Read 3361 bytes of print data...
D [28/Nov/2010:14:44:29 -0500] [Job 3071] Wrote 3361 bytes of print data...
I [28/Nov/2010:14:44:29 -0500] [Job 3071] Print file sent, waiting for printer to finish...

Which is the point at which the printer actually starts producing output. A full 10 seconds later.

I experience some of the same. I'm not sure if this is the same problem as you, but we experince that with receipt-printers, some of them suddenly started having a 4 seconds delay when printing, while others came straight away.

This was after an Cups upgrade (Slackware linux).

After a lot of debugging, we have found that the printers supporting SNMP doesn't have the delay, while printers not supporting SNMP does have the delay.

It seems cups, after the upgrade, is trying to fetch info from the printer by SNMP before sending the actual printjob.

I'm now looking for a way to disable this feature... Will try to write back if I find a solution.

I should mention that we are using raw/socket connection to these printers. I see RedHat has a reported bug about this, but I'm not allowed to view it (BZ#709896)

I can't really find out how I can disable the SNMP-communication in Cups. :

I would suggest looking at the following post in ubuntuforums, as they seem to have a communication issue with the printer too.

http://ubuntuforums.org/showthread.php?t=1101273

hope that helps,
RayQuang

I have same experience with user127222. For some printers with no SNMP supported, the print jobs will have 4 seconds delay. After study those code in CUPS:

 if ((ppd = ppdOpenFile(getenv("PPD"))) == NULL ||
 ((ppdattr = ppdFindAttr(ppd, "cupsSNMPSupplies", NULL)) != NULL &&
 ppdattr->value && _cups_strcasecmp(ppdattr->value, "true")))
 
 ppdClose(ppd);
 return;
 

I find that I could disable these SNMP requests by updating PPD file for that printer.
Using:

*cupsSNMPSupplies: False

Ref: CUPS PPD Extensions

A potential unrelated answer to your question but was certainly the answer to my question was for a local USB thermal printer -- why was it causing a delay of 5 seconds between prints.

The solution turned out to be that not all USB printers should be setup as bi-directional communication like CUPS wants to do. So setting up a "quirk" for the printer in the /usr/share/cups/usb area of cups to include the specific printer "ID"and setting flags such as "unidir" "no-reattach" "soft-reset" seemed to entirely fix the issue for me. Hopefully anyone looking for the same issue can save a few hours debugging into the cups code to understand what was obvious once i keyed in on the debug output that said it was waiting for the USB read thread to exit (apparently 5 seconds).