Bug 219330

You haven't said which version of CUPS you're using, but the line numbers don't
seem to match either the current updates-testing package (1.2.7-1.5.fc6) or the
current updates package (1.2.7-1.3.fc6).  In fact, it would appear to match
cups-1.2.4-9.

So try applying the updates.

You've not said how repeatable this is (is this the reason you've not been able
to print since FC6?).  Does the ipp backend do this every time you submit a job
to that printer?

cups-libs-1.2.7-1.5.fc6
cups-debuginfo-1.2.7-1.5.fc6

I still get the same thing:
#0  0x00764402 in __kernel_vsyscall ()
#1  0x00448e56 in time () from /lib/libc.so.6
#2  0x002ae6f6 in httpRead2 (http=0x9342438, buffer=0xbfa52e59 ",A", length=8)
at http.c:1232
#3  0x002b4386 in ipp_read_http (http=0x9342438, buffer=0xbfa52e59 ",A",
length=8) at ipp.c:2759
#4  0x002b3f05 in ippReadIO (src=0x9342438, cb=0x2b41e0 <ipp_read_http>,
blocking=1, parent=0x0, ipp=0x9346470) at ipp.c:1054
#5  0x002b4149 in ippRead (http=0x0, ipp=0x2cf8a4) at ipp.c:991
#6  0x002c03f2 in cupsDoFileRequest (http=0x9342438, request=0x93422f8,
resource=0xbfa6de68 "/printers/GSS", filename=0xbfa70d3a
"/var/spool/cups/d00013-001") at request.c:346
#7  0x0085846b in main (argc=7, argv=0xbfa6ec14) at ipp.c:971

I haven't been able to print to this particular printer since FC6 was installed
on this machine (it worked great under RHEL4 before that). I can repeat it every
time trying to print to this particular printer.

Part of the problem here is that the remote error (that the LPD host is down)
does not get reportedly locally.  I reported this upstream in November.

Busy loop condition reported upstream.  Pity we weren't able to catch it with
strace. :-(

I have an issue that looks very similar to this with samba printing. I was going
to file it under samba until I found this entry. If I need to file this as a
seperate issue please let me know.

The problem that I'm having is that samba processes will occasionally go to 100%
cpu usage and stay there until killed. On our system this happens several times
a day on average.

Here is the information I gathered for my problem.

Strace of afflicted process:

Process 30782 attached - interrupt to quit
time(NULL)                              = 1167861753
recv(27, "", 2048, 0)                   = 0
time(NULL)                              = 1167861753
recv(27, "", 2048, 0)                   = 0
time(NULL)                              = 1167861753
recv(27, "", 2048, 0)                   = 0
time(NULL)                              = 1167861753
recv(27, "", 2048, 0)                   = 0
time(NULL)                              = 1167861753
recv(27, "", 2048, 0)                   = 0
time(NULL)                              = 1167861753
recv(27, "", 2048, 0)                   = 0
time(NULL)                              = 1167861753
(it keeps going until killed)


checked to see what it was stuck on

# ls -al /proc/30782/fd/27
l-wx------ 1 root root 64 Jan  3 13:40 /proc/30782/fd/27 -> socket:[13057635]


Checking to see what it's trying to talk to

# grep 13057635 /proc/net/tcp
 450: 0100007F:9CCD 0100007F:0277 08 00000000:00000000 00:00000000 00000000    
0        0 13057635 1 cde21a80 205 40 26 2 100  

# netstat -np |grep 30782
tcp       38      0 66.xxx.xxx.xxx:52436        66.xxx.xxx.xxx:389         
CLOSE_WAIT  30782/smbd          
tcp        0      0 66.xxx.xxx.xxx:445          10.xx.xx.xxx:1112          
ESTABLISHED 30782/smbd          
tcp        0      0 127.0.0.1:40141             127.0.0.1:631              
CLOSE_WAIT  30782/smbd  

Backstrace of process

#0  0x00110402 in __kernel_vsyscall ()
#1  0x00170061 in recv () from /lib/libpthread.so.0
#2  0x00dfcb18 in httpRead2 () from /usr/lib/libcups.so.2
#3  0x00e02386 in ippRead () from /usr/lib/libcups.so.2
#4  0x00e01855 in ippReadIO () from /usr/lib/libcups.so.2
#5  0x00e02149 in ippRead () from /usr/lib/libcups.so.2
#6  0x00e0e3f2 in cupsDoFileRequest () from /usr/lib/libcups.so.2
#7  0x00e0e98e in cupsDoRequest () from /usr/lib/libcups.so.2
#8  0x00c1ebd4 in cups_cache_reload () from /usr/sbin/smbd
#9  0x00c1caaf in pcap_cache_reload () from /usr/sbin/smbd
#10 0x00ceaca1 in reload_printers () from /usr/sbin/smbd
#11 0x00ad1d33 in check_reload () from /usr/sbin/smbd
#12 0x00ad1e55 in check_reload () from /usr/sbin/smbd
#13 0x00ad278e in smbd_process () from /usr/sbin/smbd
#14 0x00cec8e0 in main () from /usr/sbin/smbd


Not all of the packages on this server are up to date, but the ones that I
thought were relevent to this problem are:

samba-3.0.23c-2
cups-1.2.7-1.5.fc6
cups-libs-1.2.7-1.5.fc6
glibc-2.5-3

It appears to me that the cups library is in a loop reading from the network
connection to cupsd (127.0.0.1:631) which appears to be closed (according to
netstat).

Please try cups-1.2.7-1.6.fc6 from updates-testing:

yum --enablerepo=updates-testing update 'cups*'

The updated package didn't help my problem. The strace is the same and the
backtrace is the same except for the addresses.

Please install cups-debuginfo from updates-testing-debuginfo so we can get a
better backtrace (i.e. with line numbers):

yum --enablerepo=updates-testing-debuginfo install cups-debuginfo

Thanks.

Here is a backtrace after the debuginfo was installed.


#0  0x00830402 in __kernel_vsyscall ()
#1  0x009ed061 in recv () from /lib/libpthread.so.0
#2  0x009a6b18 in httpRead2 (http=0x93ef1c0, buffer=0xbfb8a899 "none", length=1)
at /usr/include/bits/socket2.h:35
#3  0x009ac376 in ipp_read_http (http=0x93ef1c0, buffer=0xbfb8a899 "none",
length=1) at ipp.c:2759
#4  0x009ab84d in ippReadIO (src=0x93ef1c0, cb=0x9ac1d0 <ipp_read_http>,
blocking=1, parent=0x0, ipp=0x9406340) at ipp.c:1101
#5  0x009ac139 in ippRead (http=0x9c7884, ipp=0xbfb8a760) at ipp.c:991
#6  0x009b83e2 in cupsDoFileRequest (http=0x93ef1c0, request=0x93c5570,
resource=0x4fc159 "/", filename=0x0) at request.c:346
#7  0x009b897e in cupsDoRequest (http=0x93ef1c0, request=0x93c5570,
resource=0x4fc159 "/") at request.c:451
#8  0x003d1bd4 in cups_cache_reload () from /usr/sbin/smbd
#9  0x003cfaaf in pcap_cache_reload () from /usr/sbin/smbd
#10 0x0049dca1 in reload_printers () from /usr/sbin/smbd
#11 0x00284d33 in check_reload () from /usr/sbin/smbd
#12 0x00284e55 in check_reload () from /usr/sbin/smbd
#13 0x0028578e in smbd_process () from /usr/sbin/smbd
#14 0x0049f8e0 in main () from /usr/sbin/smbd

Thanks.  Passed along upstream.

Fixed in update: cups-1.2.7-1.7.fc6

updated to cups*-1.2.7-1.7.fc6 from updates-testing and I'm still seeing the
same problem.

Oops, I shouldn't have closed this.

*** Bug 222160 has been marked as a duplicate of this bug. ***

Please try cups-1.2.7-1.8.fc6, shortly to appear in updates-testing.

After running cups-1.2.7-1.8.fc6 for three days the problem has not reoccurred,
so I believe the problem is fixed.