Totally odd kde vs print problem

Gene Heskett gene.heskett at verizon.net
Mon Jun 28 23:39:38 CEST 2004


Greetings;

I've searched the archives for anything that might be related to my 
problem and have come up blank.  So I'm gonna hit you all with a big 
one because I can't get any closer to it than whats below without 
crashing major hunks of kde, like the toolbar at the bottom of the 
screen.

Here is the outline:

kernel=2.6.7-rc3-mm2, subject to change, doesn't seem to effect this

Machine is an RH8 install, updated to FC1.

The kde install is a konstruct built install of kde3.2.3, installed 
in /root/kde3.2.3 with all env paths set accordingly (I think)

cups etc is all hand built, and I have 4 printers defined in cups, 
where lp0 is an Epson photo 820 running in utility resolution, lp1 is 
that same printer running in photo quality resolution, lp2 is an 
Epson C82 running in utility resolution, and lp3 is that same Epson 
C82 running in photo resolution.  Test pages from cups work on all 4 
printers, although the photo 820 is about to hit the bin, I cannot 
keep the nozzles clean, and its inks aren't photo quality either.

This works just fine in that I can print from mozilla, or the command 
line, acrobat, xpdf, gimp etc, all works as expected.

The problem is that nothing from kde can print, any attempt to access 
a printer from any print enabled kde app will open the dialog window 
for maybe 1 second, then the dialog window goes away, along with the 
app that tried to open a path to a printer, whether its the toolbar, 
kmail, kwrite, kate etc.  If its the toolbar it kills, then the only 
way out of X to  restart it is ctl-alt-backspace as there is no 
window changer available to do gracefull shutdowns with.  Messy, 
particularly for kmail, because of the way it marks messages.

I have /etc/cups/cupsd.conf set at "DebugLevel debug2" and have 
restarted cups.

From the error log on restarting cups with full debugging
D [28/Jun/2004:17:18:11 -0400] LoadAllJobs: Loading attributes for job 
280...
I [28/Jun/2004:17:18:11 -0400] Full reload complete.
D [28/Jun/2004:17:18:11 -0400] StartListening: NumListeners=1
D [28/Jun/2004:17:18:11 -0400] StartListening: address=00000000 
port=631
D [28/Jun/2004:17:18:11 -0400] ResumeListening: setting input bits...
d [28/Jun/2004:17:18:11 -0400] ResumeListening: Adding fd 0 to 
InputSet...
d [28/Jun/2004:17:18:11 -0400] StartBrowsing: Adding fd 2 to 
InputSet...
d [28/Jun/2004:17:18:11 -0400] StartServer: Adding fd 3 to InputSet...
d [28/Jun/2004:17:18:11 -0400] AddCert: adding certificate for pid 0

This is the "strace kcmshell printmgr" output, with lots of snipping, 
tons of it at the start.

[...]
open("/etc/hosts", O_RDONLY)            = 11
fcntl64(11, F_GETFD)                    = 0
fcntl64(11, F_SETFD, FD_CLOEXEC)        = 0
fstat64(11, {st_mode=S_IFREG|0644, st_size=291, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 
0) = 0x41b33000
read(11, "# Do not remove the following li"..., 4096) = 291
close(11)                               = 0
munmap(0x41b33000, 4096)                = 0
time(NULL)                              = 1088457800
socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 11
fcntl64(11, F_SETFD, FD_CLOEXEC)        = 0
setsockopt(11, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
setsockopt(11, SOL_TCP, TCP_NODELAY, [1], 4) = 0
connect(11, {sa_family=AF_INET, sin_port=htons(631), 
sin_addr=inet_addr("127.0.0.1")}, 16) = 0
send(11, "POST /printers/ HTTP/1.1\r\n", 26, 0) = 26
send(11, "Content-Length: 112\r\n", 21, 0) = 21
send(11, "Content-Type: application/ipp\r\n", 31, 0) = 31
send(11, "Host: localhost\r\n", 17, 0)  = 17
send(11, "\r\n", 2, 0)                  = 2
time(NULL)                              = 1088457801
send(11, "\1\1@\2\0\0\0\1", 8, 0)       = 8
time(NULL)                              = 1088457801
send(11, "\1G\0\22attributes-charset\0\5utf-8", 29, 0) = 29
time(NULL)                              = 1088457801
send(11, "H\0\33attributes-natural-language\0\5"..., 37, 0) = 37
time(NULL)                              = 1088457801
send(11, "D\0\24requested-attributes\0\fprinter"..., 37, 0) = 37
time(NULL)                              = 1088457801
send(11, "\3", 1, 0)                    = 1
recv(11, "HTTP/1.1 200 OK\r\nDate: Mon, 28 J"..., 2048, 0) = 1260
time(NULL)                              = 1088457801
time(NULL)                              = 1088457801
time(NULL)                              = 1088457801
time(NULL)                              = 1088457801
time(NULL)                              = 1088457801
time(NULL)                              = 1088457801
time(NULL)                              = 1088457801
time(NULL)                              = 1088457801
time(NULL)                              = 1088457801
brk(0)                                  = 0x81f0000
brk(0x81f1000)                          = 0x81f1000
brk(0)                                  = 0x81f1000
brk(0)                                  = 0x81f1000
brk(0x81f2000)                          = 0x81f2000
close(11)                               = 0
--- SIGSEGV (Segmentation fault) @ 0 (0) ---
rt_sigaction(SIGALRM, {SIG_DFL}, {SIG_DFL}, 8) = 0
alarm(3)                                = 0
sched_yield()                           = 0
[...]
sched_yield()                           = 0
nanosleep({0, 2000001}, NULL)           = 0
sched_yield()                           = 0
[...]
sched_yield()                           = 0
nanosleep({0, 2000001}, NULL)           = 0
sched_yield()                           = 0
[...]
sched_yield()                           = 0
nanosleep({0, 2000001}, NULL)           = 0
sched_yield()                           = 0
[...]
sched_yield()                           = 0
nanosleep({0, 2000001}, NULL)           = 0
sched_yield()                           = 0
[...]
sched_yield()                           = 0
--- SIGALRM (Alarm clock) @ 0 (0) ---
+++ killed by SIGALRM +++
[root at coyote root]#

It got as far as showing the little "initializing manager" with the 
printer icon on its left for about 1 second before it all went away.

And I have my shell promt back.

The cups error log now has this added:

d [28/Jun/2004:17:23:11 -0400] DeleteCert: removing certificate for 
pid 0
d [28/Jun/2004:17:23:11 -0400] AddCert: adding certificate for pid 0
d [28/Jun/2004:17:23:20 -0400] AcceptClient(0x80877b8) 0 NumClients = 
0
D [28/Jun/2004:17:23:20 -0400] AcceptClient() 6 from localhost:631.
d [28/Jun/2004:17:23:20 -0400] AcceptClient: Adding fd 6 to 
InputSet...
d [28/Jun/2004:17:23:20 -0400] ReadClient() 6, used=0
D [28/Jun/2004:17:23:20 -0400] CloseClient() 6
d [28/Jun/2004:17:23:20 -0400] CloseClient: Removing fd 6 from 
InputSet and OutputSet...
d [28/Jun/2004:17:23:20 -0400] AcceptClient(0x80877b8) 0 NumClients = 
0
D [28/Jun/2004:17:23:20 -0400] AcceptClient() 6 from localhost:631.
d [28/Jun/2004:17:23:20 -0400] AcceptClient: Adding fd 6 to 
InputSet...
d [28/Jun/2004:17:23:20 -0400] ReadClient() 6, used=0
D [28/Jun/2004:17:23:20 -0400] ReadClient() 6 POST /printers/ HTTP/1.1
d [28/Jun/2004:17:23:21 -0400] decode_auth(0x4065b008): Authorization 
string = ""
d [28/Jun/2004:17:23:21 -0400] decode_auth() 6 username=""
d [28/Jun/2004:17:23:21 -0400] IsAuthorized: con->uri = "/printers/"
d [28/Jun/2004:17:23:21 -0400] FindBest: uri = "/printers/"...
d [28/Jun/2004:17:23:21 -0400] FindBest: Location / Limit 7f
d [28/Jun/2004:17:23:21 -0400] FindBest: Location /admin Limit 7f
d [28/Jun/2004:17:23:21 -0400] FindBest: best = "/"
d [28/Jun/2004:17:23:21 -0400] IsAuthorized: auth = 0, satisfy=0...
d [28/Jun/2004:17:23:21 -0400] POST /printers/
d [28/Jun/2004:17:23:21 -0400] CONTENT_TYPE = application/ipp
d [28/Jun/2004:17:23:21 -0400] ReadClient() 6 con->data_encoding = 
length, con->data_remaining = 112, con->file = 0
d [28/Jun/2004:17:23:21 -0400] ReadClient() 6, used=0
d [28/Jun/2004:17:23:21 -0400] ReadClient() 6 con->data_encoding = 
length, con->data_remaining = 104, con->file = 0
d [28/Jun/2004:17:23:21 -0400] ReadClient() 6, used=0
d [28/Jun/2004:17:23:21 -0400] ReadClient() 6 con->data_encoding = 
length, con->data_remaining = 75, con->file = 0
d [28/Jun/2004:17:23:21 -0400] ReadClient() 6, used=0
d [28/Jun/2004:17:23:21 -0400] ReadClient() 6 con->data_encoding = 
length, con->data_remaining = 38, con->file = 0
d [28/Jun/2004:17:23:21 -0400] ReadClient() 6, used=0
d [28/Jun/2004:17:23:21 -0400] ReadClient() 6 con->data_encoding = 
length, con->data_remaining = 1, con->file = 0
d [28/Jun/2004:17:23:21 -0400] ProcessIPPRequest(0x4065b008[6]): 
operation_id = 4002
d [28/Jun/2004:17:23:21 -0400] get_printers(0x4065b008[6], 0)
d [28/Jun/2004:17:23:21 -0400] add_printer_state_reasons(0x4065b008
[6], 0x808b818[lp0])
d [28/Jun/2004:17:23:21 -0400] add_queued_job_count(0x4065b008[6], 
0x808b818[lp0])
d [28/Jun/2004:17:23:21 -0400] copy_attrs(0x823b2c0, 0x808f740, 
0x823cf18, 0)
d [28/Jun/2004:17:23:21 -0400] copy_attribute(0x823b2c0, 0x808f8a8
[printer-name,4,42])
d [28/Jun/2004:17:23:21 -0400] copy_attrs(0x823b2c0, 0x808db80, 
0x823cf18, 0)
d [28/Jun/2004:17:23:21 -0400] add_printer_state_reasons(0x4065b008
[6], 0x80989a8[lp1])
d [28/Jun/2004:17:23:21 -0400] add_queued_job_count(0x4065b008[6], 
0x80989a8[lp1])
d [28/Jun/2004:17:23:21 -0400] copy_attrs(0x823b2c0, 0x8099600, 
0x823cf18, 0)
d [28/Jun/2004:17:23:21 -0400] copy_attribute(0x823b2c0, 0x808fe18
[printer-name,4,42])
d [28/Jun/2004:17:23:21 -0400] copy_attrs(0x823b2c0, 0x808db80, 
0x823cf18, 0)
d [28/Jun/2004:17:23:21 -0400] add_printer_state_reasons(0x4065b008
[6], 0x8095e70[lp2])
d [28/Jun/2004:17:23:21 -0400] add_queued_job_count(0x4065b008[6], 
0x8095e70[lp2])
d [28/Jun/2004:17:23:21 -0400] copy_attrs(0x823b2c0, 0x808ff50, 
0x823cf18, 0)
d [28/Jun/2004:17:23:21 -0400] copy_attribute(0x823b2c0, 0x8091b28
[printer-name,4,42])
d [28/Jun/2004:17:23:21 -0400] copy_attrs(0x823b2c0, 0x808db80, 
0x823cf18, 0)
d [28/Jun/2004:17:23:21 -0400] add_printer_state_reasons(0x4065b008
[6], 0x8097078[lp3])
d [28/Jun/2004:17:23:21 -0400] add_queued_job_count(0x4065b008[6], 
0x8097078[lp3])
d [28/Jun/2004:17:23:21 -0400] copy_attrs(0x823b2c0, 0x8097548, 
0x823cf18, 0)
d [28/Jun/2004:17:23:21 -0400] copy_attribute(0x823b2c0, 0x808fd08
[printer-name,4,42])
d [28/Jun/2004:17:23:21 -0400] copy_attrs(0x823b2c0, 0x808db80, 
0x823cf18, 0)
D [28/Jun/2004:17:23:21 -0400] ProcessIPPRequest: 6 status_code=1
d [28/Jun/2004:17:23:21 -0400] ProcessIPPRequest: Adding fd 6 to 
OutputSet...
d [28/Jun/2004:17:23:21 -0400] WriteClient: Removing fd 6 from 
OutputSet...
d [28/Jun/2004:17:23:21 -0400] ReadClient() 6, used=0
D [28/Jun/2004:17:23:21 -0400] CloseClient() 6
d [28/Jun/2004:17:23:21 -0400] CloseClient: Removing fd 6 from 
InputSet and OutputSet...

Is there anything here that would point me towards a more informative 
level of troubleshooting?  This problem has been endemic on this 
machine for over a year, and several versions of both kde and cups.  
And its a PITA to have to save a mail, and then go find it and print 
it from the command line if I want a permanent record.

-- 
Cheers, Gene
There are 4 boxes to be used in defense of liberty. 
Soap, ballot, jury, and ammo.
Please use in that order, starting now.  -Ed Howdershelt, Author
Additions to this message made by Gene Heskett are Copyright 2004, 
Maurice E. Heskett, all rights reserved.


More information about the kde-print mailing list