[cups.general] lpr through printserver fails in 1 out of 30

[Rebecca Simmons]

I have 30 identical printers set up with the client machines using lpr  
to print to them through a central printserver (called printserver).   
29 of these machines behave as expected.  The 30th one can be printed  
to if the managed client is using a bonjour connection to the  
printserver but not if using an lpr connection to the printserver.   
With the lpr connection the client gets an instant paused printer, and  
the job never gets to printserver to be queued.  I've set the cups log  
to debug 2 on the client and I think the problem is covered by the  
part below where cupsdDoSelect: polling keeps returning a status 1 (am  
I right in thinking the "1" here means "failed"?).  The strange thing  
is that I can print to the selected printer from the client through  
the printserver with lpr through the command line using

lpr -H printserver.gns -P pr_br_upper /testprint.rtf

Does anyone have an idea how I can fix this? Or even suggestions for  
further troubleshooting steps?

Thanks

d [28/Mar/2011:10:11:09 -0700] POST /
d [28/Mar/2011:10:11:09 -0700] CONTENT_TYPE = application/ipp
d [28/Mar/2011:10:11:09 -0700] cupsdReadClient: 20 con- 
 >data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=196, con- 
 >file=-1
d [28/Mar/2011:10:11:09 -0700] cupsdProcessIPPRequest(0x7b000[20]):  
operation_id = 000b
D [28/Mar/2011:10:11:09 -0700] Get-Printer-Attributes ipp://localhost/ 
printers/pr_br_upper
d [28/Mar/2011:10:11:09 -0700] get_printer_attrs(0x7b000[20], ipp:// 
localhost/printers/pr_br_upper)
d [28/Mar/2011:10:11:09 -0700] cupsdFindPolicyOp(p=0x219870, op=b(Get- 
Printer-Attributes))
d [28/Mar/2011:10:11:09 -0700] cupsdFindPolicyOp: Found wildcard  
match...
d [28/Mar/2011:10:11:09 -0700] cupsdIsAuthorized: con->uri="/", con- 
 >best=0x10ee90((null))
d [28/Mar/2011:10:11:09 -0700] cupsdIsAuthorized:  
level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL,  
num_names=0
d [28/Mar/2011:10:11:09 -0700] cupsdIsAuthorized: op=0(unknown-0000)
d [28/Mar/2011:10:11:09 -0700] cupsdIsAuthorized:  
auth=CUPSD_AUTH_ALLOW...
d [28/Mar/2011:10:11:09 -0700] copy_attrs(to=0x23c900, from=0x200160,  
ra=0x23c970, group=0, quickcopy=0)
d [28/Mar/2011:10:11:09 -0700] copy_attribute(0x23c900,  
0x11d0d0[printer-info,4,41])
d [28/Mar/2011:10:11:09 -0700] copy_attrs(to=0x23c900, from=0x110000,  
ra=0x23c970, group=0, quickcopy=-2147483648)
D [28/Mar/2011:10:11:09 -0700] cupsdProcessIPPRequest: 20  
status_code=0 (successful-ok)
d [28/Mar/2011:10:11:09 -0700] cupsdAddSelect: fd=20,  
read_cb=0x182270f3, write_cb=0x182252b6, data=0x7b000
d [28/Mar/2011:10:11:09 -0700] cupsdDoSelect: polling 13 fds for 1  
seconds...
d [28/Mar/2011:10:11:09 -0700] cupsdDoSelect: kevent(3, ...,  
16384, ...) returned 1...
d [28/Mar/2011:10:11:09 -0700] event->filter=-2, event->ident=20
d [28/Mar/2011:10:11:09 -0700] cupsdDoSelect: Write on fd 20...
d [28/Mar/2011:10:11:09 -0700] cupsdDoSelect: polling 13 fds for 1  
seconds...
d [28/Mar/2011:10:11:09 -0700] cupsdDoSelect: kevent(3, ...,  
16384, ...) returned 1...
d [28/Mar/2011:10:11:09 -0700] event->filter=-2, event->ident=20
d [28/Mar/2011:10:11:09 -0700] cupsdDoSelect: Write on fd 20...
d [28/Mar/2011:10:11:09 -0700] cupsdDoSelect: polling 13 fds for 1  
seconds...
d [28/Mar/2011:10:11:09 -0700] cupsdDoSelect: kevent(3, ...,  
16384, ...) returned 1...
d [28/Mar/2011:10:11:09 -0700] event->filter=-2, event->ident=20
d [28/Mar/2011:10:11:09 -0700] cupsdDoSelect: Write on fd 20...
d [28/Mar/2011:10:11:09 -0700] cupsdDoSelect: polling 13 fds for 1  
seconds...
d [28/Mar/2011:10:11:09 -0700] cupsdDoSelect: kevent(3, ...,  
16384, ...) returned 1...
d [28/Mar/2011:10:11:09 -0700] event->filter=-2, event->ident=20
d [28/Mar/2011:10:11:09 -0700] cupsdDoSelect: Write on fd 20...
d [28/Mar/2011:10:11:09 -0700] cupsdWriteClient: 20 bytes < 0
d [28/Mar/2011:10:11:09 -0700] cupsdAddSelect: fd=20,  
read_cb=0x182270f3, write_cb=0x0, data=0x7b000
d [28/Mar/2011:10:11:09 -0700] cupsdDoSelect: polling 13 fds for 1  
seconds...
d [28/Mar/2011:10:11:09 -0700] cupsdDoSelect: kevent(3, ...,  
16384, ...) returned 1...
d [28/Mar/2011:10:11:09 -0700] event->filter=-1, event->ident=24
d [28/Mar/2011:10:11:09 -0700] cupsdDoSelect: Read on fd 24...
D [28/Mar/2011:10:11:09 -0700] [Job 2123] lpd_command returning 1
d [28/Mar/2011:10:11:09 -0700] process_children()
E [28/Mar/2011:10:11:09 -0700] PID 4162 (/usr/libexec/cups/backend/ 
lpd) stopped with status 1!
d [28/Mar/2011:10:11:09 -0700] cupsdDoSelect: polling 13 fds for 1  
seconds...
d [28/Mar/2011:10:11:09 -0700] cupsdDoSelect: kevent(3, ...,  
16384, ...) returned 1...
d [28/Mar/2011:10:11:09 -0700] event->filter=-1, event->ident=24
d [28/Mar/2011:10:11:09 -0700] cupsdDoSelect: Read on fd 24...
D [28/Mar/2011:10:11:09 -0700] [Job 2123] File 0 is complete.
d [28/Mar/2011:10:11:09 -0700] [Job 2123] cupsdFinishJob: job->status  
is -256
d [28/Mar/2011:10:11:09 -0700] cupsdRemoveSelect: fd=24
d [28/Mar/2011:10:11:09 -0700] [Job 2123] cupsdFinishJob: Closing  
status pipes [ 24 -1 ]...
I [28/Mar/2011:10:11:09 -0700] [Job 2123] Backend returned status 1  
(failed)
____________________________________
Rebecca Simmons
Technology Services, Glenlyon Norfolk School

rsimmons at mygns.ca	

Glenlyon Norfolk School
801 Bank Street
Victoria, British Columbia
Canada V8S 4A8

Tel: 1+250-370-6860