Bug 592698

Please take a look at this page which gives some ideas about how to find the problem, and what information we need in order to help diagnose it:

https://fedoraproject.org/wiki/Printing/Debugging

(In reply to comment #1)
> Please take a look at this page which gives some ideas about how to find the
> problem, and what information we need in order to help diagnose it:
> 
> https://fedoraproject.org/wiki/Printing/Debugging    

Hi Tim,

Thank you for directing me to page. I think i have gethered some information that could be useful to you.
First i have emptied cups error_log file, then i turned cups debugging on (level2). Afterwards i submitted job (tried to print out letter).
All ended by pop up window saying that print job didn't go well.
More technical information, i guess, you will find in attached files. Hopefully resolution comes quick. I use fedora for my business - printer bug means no printing for my business...(yes i know their is RH for that), but anyways....

Created attachment 414394 [details]
cups_error_log

Created attachment 414395 [details]
lpinfo output

Created attachment 414396 [details]
printer driver in use

Thanks for proving that information.

So first the dnssd backend get executed.  All that backend does is resolve the DNS-SD name and then execute whichever other backend can actually transfer the data to the device.  In this case it is the socket backend:

D [16/May/2010:19:30:14 +0200] [Job 21] Resolving "Officejet J6400 series [DF7CB5]", regtype="_pdl-datastream._tcp", domain="local."...
D [16/May/2010:19:30:14 +0200] [Job 21] Resolved as "socket://10.0.1.3:9100"...
D [16/May/2010:19:30:14 +0200] [Job 21] Executing backend "/usr/lib/cups/backend/socket"...

The socket backend manages to connect to the printer but some time later this connection fails:

E [16/May/2010:19:44:45 +0200] [Job 21] Unable to write print data: Broken pipe

(this comes from the write-data loop in backend/runloop.c)

So the question is: why did the TCP connection fail?

To know the answer I think we'll need to see what the TCP traffic actually looks like.  Please run this command as root:

tcpdump -l host 10.0.1.3 | tee tcp.log

while sending the print job, and when it fails press Control-C to stop the tcpdump command.  Then please attach the tcp.log file to this bug report using the "Add an attachment" link above.

Hi Tim,

I'm afraid i got just meaningless stuff here. Take a look at tcp.log in attachments.

Created attachment 415029 [details]
tcp.log

Did you run tcpdump on the CUPS server machine?

Maybe just run "tcpdump -n -l > tcp.log", or run wireshark.  I'm not sure why we aren't seeing any of the TCP connection at all.

Hi Tim,

Of course i tcpdump on CUPS server machine :) .
First tcpdump that i posted was output of the following command:
tcpdump -i wlan0 -l host 10.0.1.3 | tee tcp.log

My laptop, and printer as well, are wireless. Because whole tcpdump made not much sense i sought let me wire at last my laptop for now (easiest at this point) and try again.
I ran following command this time:
tcpdump -i eth0 -l host 10.0.1.3 | tee tcp.log

and i got some what more information out of tcpdump. Please take a look.

This evening i want to try wire printer as well and try it again, see what happens.

Created attachment 415338 [details]
tcpdump_wiredLaptop_wirelesPrinter

Ok...I have wired printer too. Very interesting development. When i try to print i get error: "There was a problem sending document 'blabla' (job 34)to the printer".
I click ok and window pops-up asking me if i want to diagnose the problem. I click yes and it comes up with answer: "The queue "HP-OfficeJet is not enabled the reason given is '/usr/lib/cups/backend/dnssd failed'" 
And it asks me to enable it from System-Administration-Printing menu. Which i do of course.
But when i try to print again is see in printer settings window that it gets disabled which results in the same error message all over again.
I did tcpdump of this communication but then again it is as useful as first one.

Created attachment 415358 [details]
tcpdump_both_wired

This time i wired them both. Although tcpdump still doesn't make a lot of sense.

In the last tcpdump i see following line:
IP 10.0.1.6 > 10.0.1.1: ICMP host 10.0.1.6 unreachable - admin prohibited,
length 96

I think this is the moment that i get asked to enable printer from settings
menu  ("polices" tab).
But it gets disabled as soon as i try to submit new print (job).

Niko, we are not seeing the entire conversation in any of these traces.  The 'admin prohibited' message is just about an SNMP response, which is not required for being able to print -- but we don't see the corresponding query that the response is an answer to.

In your error_log in comment #3 we see this:

D [16/May/2010:19:30:14 +0200] [Job 21] Executing backend "/usr/lib/cups/backend/socket"...
D [16/May/2010:19:30:14 +0200] [Job 21] STATE: +connecting-to-device
D [16/May/2010:19:30:14 +0200] [Job 21] Looking up "10.0.1.3"...
D [16/May/2010:19:30:14 +0200] [Job 21] Connecting to 10.0.1.3:9100
I [16/May/2010:19:30:14 +0200] [Job 21] Connecting to printer...
D [16/May/2010:19:30:14 +0200] [Job 21] STATE: -connecting-to-device
I [16/May/2010:19:30:14 +0200] [Job 21] Connected to printer...
D [16/May/2010:19:30:14 +0200] [Job 21] Connected to 10.0.1.3:9100 (IPv4)...

which is a successful TCP connection to 10.0.1.3 from your CUPS server (presumably 10.0.1.6?).  So when tracing it, we expect to see at least these packets:

10.0.1.6 > 10.0.1.3 SYN
10.0.1.3 > 10.0.1.6 SYN ACK
10.0.1.6 > 10.0.1.3 ACK

But they are not there. :-/  This is the connection we need to be able to watch.

Let's start at the beginning.  What do '/sbin/ifconfig' and '/sbin/route -n' say?

Hi Tim,

I have switched wlan off and now laptop (10.0.1.6) as well as printer (10.0.1.1) are wired. So let's do this...

#ifconfig
eth0      Link encap:Ethernet  HWaddr 00:24:BE:5A:9C:B2  
          inet addr:10.0.1.6  Bcast:10.0.1.255  Mask:255.255.255.0
          inet6 addr: fe80::224:beff:fe5a:9cb2/64 Scope:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:627 errors:0 dropped:0 overruns:0 frame:0
          TX packets:729 errors:0 dropped:0 overruns:0 carrier:1
          collisions:0 txqueuelen:1000 
          RX bytes:347429 (339.2 KiB)  TX bytes:138135 (134.8 KiB)
          Interrupt:29 

lo        Link encap:Local Loopback  
          inet addr:127.0.0.1  Mask:255.0.0.0
          inet6 addr: ::1/128 Scope:Host
          UP LOOPBACK RUNNING  MTU:16436  Metric:1
          RX packets:8 errors:0 dropped:0 overruns:0 frame:0
          TX packets:8 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0 
          RX bytes:480 (480.0 b)  TX bytes:480 (480.0 b)

#route -n
Kernel IP routing table
Destination     Gateway         Genmask         Flags Metric Ref    Use Iface
10.0.1.0        0.0.0.0         255.255.255.0   U     1      0        0 eth0
0.0.0.0         10.0.1.254      0.0.0.0         UG    0      0        0 eth0

Forgot to add, to avoid confusion...10.0.1.3 was printer when it was hooked up to wlan. But now wired nic got 10.0.1.1 ip addr.
And 10.0.1.6 is my laptop (wired nic).

OK.... this is what happened.
I deleted printer, restarted cups added printer again, but now beeing connected through wire. In the end of "printer adding" wizard i was asked to print a test page. i ran tcpdump command (just in case) and WHOILLA - test page is printed.

I'm attaching new tcpdump here take a look, all those SIN ACk you have mentioned are there, well obviously - page was printed right?

So next what i'm gonna do is set printer up again but only with wireless to see if it goes wrong again.
If it does then there is something wrong with wireless communication between cups and printer.

Created attachment 415403 [details]
tcpdump_success

this time printer was set up from scratch.
I connected printer and laptop to the network through wire. Deleted printer from laptop, added it again with wizard tool from System-Administration-Printing menu. 
And it worked!!!

Next step is to repeat all this but with wireless setup. Please Tim take a look at tcpdump just to make sure that it looks ok.

(In reply to comment #17)
> Forgot to add, to avoid confusion...10.0.1.3 was printer when it was hooked up
> to wlan. But now wired nic got 10.0.1.1 ip addr.
> And 10.0.1.6 is my laptop (wired nic).    

OK, I think your problem is that your wired and wireless network share the same subnet address.  They need to use separate subnets, e.g. 10.0.1.0 and 10.0.2.0.

(In reply to comment #21)
> (In reply to comment #17)
> > Forgot to add, to avoid confusion...10.0.1.3 was printer when it was hooked up
> > to wlan. But now wired nic got 10.0.1.1 ip addr.
> > And 10.0.1.6 is my laptop (wired nic).    
> 
> OK, I think your problem is that your wired and wireless network share the same
> subnet address.  They need to use separate subnets, e.g. 10.0.1.0 and 10.0.2.0.    

I think i will disagree with you on that one. Only reason why i would separate the subnets is if i would run different DHCP severs for wired and wireless networks. I don't, my wireless router has no dhcp running, i just wanted my wireless router to be bridged to my wired router.

And after todays kernel update printer works again in wired as well as in wireless connections.
I'm very convinced (after todays update 2.6.33.4-95.fc13.i686.PAE) that it was some kernel related issue. Because when i fresh installed F13 beta printing worked very well. Then updates came in (kernel updates too of course 2.6.33.3-85.fc13.i686.PAE) and printing broke down. Todays kernel update seems to fixed this problem.
So leaving this "notabuganymore" closed. 

I would love to know what was the real reason for it not working, just for saik of learning but....everything is working now and i will not waist you time any more. 
Thanx for you input Tim.