Linux – Why is there a 10 second delay when printing on Ubuntu Server 10.04

cupslinuxprintingUbuntu

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.

Best Answer

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. :\