Bug 590632

This also affects RHEL-6.  The CUPS server may spend most of its time performing DNS lookups for its interfaces if DNS is not configured correctly.

+++ This bug was initially created as a clone of Bug #583054 +++

+++ This bug was initially created as a clone of Bug #579957 +++

comment: I am having constant problems with slow printing.
system-config-printer/Server Settings/Advanced times out with a dialog "CUPS server error/There was an HTTP error: status 1000".
No errors are being logged to /var/log/cups/error_log or /var/log/https/error_log.
httpd and the CUPS scheduler service are both running (automatic at startup).
The only printer is a locally connected BJC4100 driver name STP01419.PPD version 5.2.5.
I have a LAN with 3 computers sharing the one printer.
Printing worked under FC10 and I have only recently upgraded to FC12, with these problems starting right away.
kernel: 2.6.32.10-90.fc12.i686.PAE
release: Fedora release 12 (Constantine)


--- Additional comment from jpopelka on 2010-04-07 12:26:46 CEST ---

Are you able to somehow obtain the troubleshooter output ?
I see s-c-printer crashed when you tried to print test page in troubleshooter, but you write that "I am having constant problems with slow printing".
So you are able to print (and therefore obtain the troubleshooter output), right ?

Are you experiencing the same "slow printing" problems regardless whether you print from the locally connected machine or from some other computer on LAN ?
Or is it different ?

--- Additional comment from owlbrudder on 2010-04-16 01:49:30 CEST ---

Created an attachment (id=406964)
Output from printing troubleshooter

Requested by Jiri Popelka on 7 April 2010

--- Additional comment from owlbrudder on 2010-04-16 01:54:45 CEST ---

(In reply to comment #2)
> Are you able to somehow obtain the troubleshooter output ?
> I see s-c-printer crashed when you tried to print test page in troubleshooter,
> but you write that "I am having constant problems with slow printing".
> So you are able to print (and therefore obtain the troubleshooter output),
> right ?
> 
> Are you experiencing the same "slow printing" problems regardless whether you
> print from the locally connected machine or from some other computer on LAN ?
> Or is it different ?    

Jiri, I have been replying to this via gmail and did not realise I had to work here through Bugzilla - sorry for the delay this has caused. The content of my gmail posts is as follows:

Yes, I have been able to capture troubleshooter output - see attached. I also have the log file, which has timestamps, but it is +/-38Mb - is there any particular part of it you would like to see?.

The "slow printing" problem is this: any interaction with the CUPS server is taking one minute twenty five seconds to one minute forty five seconds, timed using my wrist watch. The document I printed to capture the trouble-shooter output was a page of random text (lorem ipsum) printed from OpenOffice. From the time I clicked Print to the time the printer started was 1:45. During the one-page print, the printer paused twice, each time for +/-1:25. Pointing Firefox to localhost:631 takes over a minute (not accurately timed yet). Connecting over my network takes well over a minute from the time I click 'Print...' until the printer dialog becomes available. It spends this time displaying the progress message "Getting printer information ...". A four-page pdf I printed over the network took over 11 minutes to complete.

Note that the output is correct and all documents have printed correctly, except for an inability to print a test page from the printer configuration/Troubleshooter dialogs.

Note also the same PC and printer did not have this problem under FC10.

Please let me know if there is anything more I can do to help.

I connected the printer to an old IBM T23 notebook (1.3Ghz CPU) and found the delays much shorter. Printing locally caused the same document to start on the printer after only 15 seconds and there was one delay of approx 10 seconds during the print. Printing from a networked notebook took approx 1 minute to start and there were two delays, one of aprox 45 seconds and the other of approx 15 seconds. I can live with these delays, so will set up the T23 as a printer server permanently on my network, but it does not solve the problem of the longer delays and crashes when the printer is connected to my desktop PC(2.8GHz CPU). As a wild idea from left field, has something changed in the parallel port driver in FC12? See also http://forums.fedoraforum.org/showthread.php?p=1351123#post1351123

Could not live with the delays after all, so booted the notebook into WinXP and shared the printer from there. Printing and getting printer properties from networked FC12 boxen is now immediate, so it does seem to be an issue with the FC12 CUPS server somewhere.

Cheers, Doug

--- Additional comment from twaugh on 2010-04-16 10:51:44 EDT ---

This is what's causing the delay, at a guess:

'D [10/Apr/2010:09:00:20 +1000] cupsdNetIFUpdate: "lo" = localhost:631',
'D [10/Apr/2010:09:00:37 +1000] cupsdNetIFUpdate: "eth0" = 192.168.0.199:631',
'D [10/Apr/2010:09:00:54 +1000] cupsdNetIFUpdate: "virbr0" = 192.168.122.1:631',
'D [10/Apr/2010:09:00:54 +1000] cupsdNetIFUpdate: "lo" = localhost:631',
'D [10/Apr/2010:09:01:11 +1000] cupsdNetIFUpdate: "eth0" = fe80::20a:48ff:fe07:499d%eth0:631',

Perhaps you have a nameserver configured that is not reachable?

Try setting "HostNameLookups off" in /etc/cups/cupsd.conf and see if that makes a difference.

--- Additional comment from owlbrudder on 2010-04-16 21:06:33 EDT ---

(In reply to comment #1)
> This is what's causing the delay, at a guess:
> 
> 'D [10/Apr/2010:09:00:20 +1000] cupsdNetIFUpdate: "lo" = localhost:631',
> 'D [10/Apr/2010:09:00:37 +1000] cupsdNetIFUpdate: "eth0" = 192.168.0.199:631',
> 'D [10/Apr/2010:09:00:54 +1000] cupsdNetIFUpdate: "virbr0" =
> 192.168.122.1:631',
> 'D [10/Apr/2010:09:00:54 +1000] cupsdNetIFUpdate: "lo" = localhost:631',
> 'D [10/Apr/2010:09:01:11 +1000] cupsdNetIFUpdate: "eth0" =
> fe80::20a:48ff:fe07:499d%eth0:631',
> 
> Perhaps you have a nameserver configured that is not reachable?
> 
> Try setting "HostNameLookups off" in /etc/cups/cupsd.conf and see if that makes
> a difference.    

Tim, thanks for the quick response. I don't know that my answers are going to be helful.

In summary, setting "HostNameLookups off" in /etc/cups/cupsd.conf made no obvious difference and my nameservers seem to be working OK. Details are as follows:

I set "HostNameLookups off" in the cupsd.conf on both the print server (old IBM T23 notebook) and the client (T61 notebook), using the Cups tool on port 631. The service was restarted automatically on both machines.

I checked that ping and ssh were working normally using named hosts, to ensure I had no general DNS issue. All machines on my LAN have hosts files containing details of all the other machines on the LAN and my (limited) understanding is that this takes precedence over DNS lookups.

On the server, it takes 3 seconds for system-config-printer to display the printer properties. From there, it takes 5 seconds from 'Print test page' before the printer starts printing. (When this machine is booted into WinXP, the equivalent actions are as good as immediate).

From the networked notebook, it takes 30 seconds for system-config-printer to display printer properties and the 'Print test page' delay is 55 seconds.

From the networked notebook, printing a test page of lorum ipsem from Open Office took the following times:
From click on Print until printer dialog appears: 4 sec
From click on OK until remote printer commences:1 min 45 sec
During print, two delays of 10 sec and 45 sec respectively.

All these results were duplicated within a small margin of error after I used system-config-network to swap the priority of the two DNS I have recorded, so I am guessing that my general DNS setup is not at fault.

I am not running my own DNS, as I believe that fully qualified entries in my hosts files are sufficient for my small LAN - is that correct?

I will be happy to run any further tests and do anything I can to help. I can only reiterate that exactly the same hardware and network configuration worked fine under FC10.

Cheers, Doug

--- Additional comment from twaugh on 2010-05-06 10:37:16 EDT ---

There was a changed committed upstream relating to this recently.  Please try cups-1.4.3-5.fc12 which incorporates it:

http://koji.fedoraproject.org/koji/buildinfo?buildID=171926

Download each package you require, then run:

su -c 'yum update --nogpgcheck cups*1.4.3-5*.rpm'

Does that fix it?

--- Additional comment from owlbrudder on 2010-05-08 03:48:48 EDT ---

(In reply to comment #3)
> There was a changed committed upstream relating to this recently.  Please try
> cups-1.4.3-5.fc12 which incorporates it:
> 
> http://koji.fedoraproject.org/koji/buildinfo?buildID=171926
> 
> Download each package you require, then run:
> 
> su -c 'yum update --nogpgcheck cups*1.4.3-5*.rpm'
> 
> Does that fix it?    

Tim, that plus an idea I got from another thread fixed it. Installing the new version cut the initial delay when printing down to +/-35 seconds. Editing /etc/hosts on the server, to add a line for the server itself at its real IP address (ie on server dennis I added a line of the form '192.168.0.150 dennis dennis.farm.home') cut the initial delay down to less than 5 seconds. I installed the new version on both client and server, but updated /etc/hosts on the server only. I don't know why that line makes a difference - I have never needed it before! Go figure.

As far as I am concerned, the problem is fixed. Thanks very much for your efforts.

Cheers, Doug.

--- Additional comment from owlbrudder on 2010-05-08 03:49:44 EDT ---

Ooops - forgot the clear the needinfo flag - hope this does it.

--- Additional comment from twaugh on 2010-05-08 08:08:47 EDT ---

Great, thanks for testing.