GNOME Bugzilla – Bug 485662
[gutsy] getting "Error Printing: Too many failed attempts" error when printing through GtkPrintOperation
Last modified: 2007-11-22 06:07:12 UTC
The bug has been opened on https://bugs.launchpad.net/bugs/145278 "Binary package hint: cupsys At some point of last weeks gutsy updates, printing got broken; printing at the commandline via lp or with xpp works; when trying to print from gnome/gtk apps which use GtkPrint I get the the error dialog window "Error Printing: Too many failed attempts"; /var/log/cups/access_log just gives localhost - - [26/Sep/2007:18:18:44 +0200] "GET /ppd/fs1010direct.ppd HTTP/1.1" 200 10982 - - localhost - - [26/Sep/2007:18:18:48 +0200] "POST /printers/fs1010direct HTTP/1.1" 400 0 unknown-0000 - localhost - - [26/Sep/2007:18:19:03 +0200] "POST /printers/FS-1010 HTTP/1.1" 400 0 unknown-0000 - /var/log/cups/error_log says: E [26/Sep/2007:18:18:48 +0200] cupsdReadClient: 7 IPP Read Error! E [26/Sep/2007:18:19:03 +0200] cupsdReadClient: 7 IPP Read Error! I tried strace(2)ing gtk-demo's Printing example, and saw amongst others, that cupsys returned a "Bad Request"-line...: socket(PF_FILE, SOCK_STREAM, 0) = 7 setsockopt(7, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0 setsockopt(7, SOL_TCP, TCP_NODELAY, [1], 4) = -1 EOPNOTSUPP (Operation not supported) fcntl64(7, F_SETFD, FD_CLOEXEC) = 0 connect(7, {sa_family=AF_FILE, path="/var/run/cups/cups.sock"}, 26) = 0 ... send(7, "POST /printers/FS-1010 HTTP/1.1\r\nContent-Length: 0\r\nContent-Type: application/ipp\r\nHost: localhost\r\nUser-Agent: CUPS/1.3.2\r\n\r\n", 126, 0) = 126 ... send(7, "\1\1\0\2\0\0\0\1\1G\0\22attributes-charset\0\5utf-8H\0\33attributes-natural-language\0\5en-gbB\0\24requesting-user-name\0\3hvrE\0\vprinter-uri\0\'ipp://cervus.intra:631/printers/FS-1010B\0\10job-name\0\17gtk-demo job #1\2B\0\10PageSize\0\2A4!\0\fjob-priority\0\4\0\0\0002B\0\nResolution\0\006800dpiB\0\njob-sheets\0\4noneB\0\0\0\4noneB\0\fJCLEconomode\0\3OffB\0\tMediaType\0\6PrnDefB\0\tSmoothing\0\6MediumB\0\tInputSlot\0\10Internal!\0\tnumber-up\0\4\0\0\0\1\3", 372, 0) = 372 poll([{fd=7, events=POLLIN, revents=POLLIN|POLLERR|POLLHUP}], 1, 0) = 1 poll([{fd=7, events=POLLIN, revents=POLLIN|POLLERR|POLLHUP}], 1, 10000) = 1 recv(7, "HTTP/1.1 400 Bad Request\r\nDate: Wed, 26 Sep 2007 16:00:55 GMT\r\nServer: CUPS/1.2\r\nContent-Language: en_US\r\nUpgrade: TLS/1.0,HTTP/1.1\r\nConnection: close\r\nContent-Type: text/html; charset=utf-8\r\nContent-Length: 344\r\n\r\n<!DOCTYPE HTML PUBLIC \"-//W3C//DTD HTML 4.0 Transitional//EN\" \"http://www.w3.org/TR/REC-html40/loose.dtd\">\n<HTML>\n<HEAD>\n\t<META HTTP-EQUIV=\"Content-Type\" CONTENT=\"text/html; charset=utf-8\">\n\t<TITLE>400 Bad Request</TITLE>\n\t<LINK REL=\"STYLESHEET\" TYPE=\"text/css\" HREF=\"/cups.css\">\n</HEAD>\n<BODY>\n<H1>400 Bad Request</H1>\n<P></P>\n</BODY>\n</HTML>\n", 2048, 0) = 559 ... some additional logs, after setting LogLevel debug2: d [01/Oct/2007:21:46:12 +0200] cupsdDoSelect: epoll() returned 1... d [01/Oct/2007:21:46:12 +0200] cupsdDoSelect: Read on fd 9... d [01/Oct/2007:21:46:12 +0200] cupsdReadClient: 9, used=0, file=-1 state=0 D [01/Oct/2007:21:46:12 +0200] cupsdReadClient: 9 POST /printers/FS-1010 HTTP/1.1 d [01/Oct/2007:21:46:12 +0200] cupsdFindBest: uri = "/printers/FS-1010"... d [01/Oct/2007:21:46:12 +0200] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0 d [01/Oct/2007:21:46:12 +0200] cupsdFindBest: Location /admin/conf Limit 7f d [01/Oct/2007:21:46:12 +0200] cupsdFindBest: Location /admin Limit 7f d [01/Oct/2007:21:46:12 +0200] cupsdFindBest: Location / Limit 7f d [01/Oct/2007:21:46:12 +0200] cupsdFindBest: best = / d [01/Oct/2007:21:46:12 +0200] cupsdAuthorize: con->uri="/printers/FS-1010", con->best=0x10084388(/) d [01/Oct/2007:21:46:12 +0200] cupsdAuthorize: Authorization="" D [01/Oct/2007:21:46:12 +0200] cupsdAuthorize: No authentication data provided. d [01/Oct/2007:21:46:12 +0200] cupsdIsAuthorized: con->uri="/printers/FS-1010", con->best=0x10084388(/) d [01/Oct/2007:21:46:12 +0200] cupsdIsAuthorized: level=AUTH_ANON, type=AUTH_NONE, satisfy=AUTH_SATISFY_ALL, num_names=0 d [01/Oct/2007:21:46:12 +0200] cupsdIsAuthorized: auth=AUTH_ALLOW... d [01/Oct/2007:21:46:12 +0200] POST /printers/FS-1010 d [01/Oct/2007:21:46:12 +0200] CONTENT_TYPE = application/ipp d [01/Oct/2007:21:46:12 +0200] cupsdReadClient: 9 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=0, con->file=-1 E [01/Oct/2007:21:46:12 +0200] cupsdReadClient: 9 IPP Read Error! D [01/Oct/2007:21:46:12 +0200] cupsdSendError: 9 code=400 (Bad Request) D [01/Oct/2007:21:46:12 +0200] cupsdCloseClient: 9 d [01/Oct/2007:21:46:12 +0200] cupsdRemoveSelect: fd=9 d [01/Oct/2007:21:46:12 +0200] cupsdCheckJobs: 0 active jobs, sleeping=0, reload=0 d [01/Oct/2007:21:46:12 +0200] cupsdDoSelect: polling 4 fds for 1 seconds... ... while looking closer at the logging output I just noticed that for some reason the request sent by the gtk apps has a "Content-Length: 0" header, which doesn't seem to be sensible..."
Created attachment 97473 [details] [review] type casting fix for zero-content-length bug sprintf was using "%lu" (on powerpc sizeof(long)==4) on a 64bit integer, which on little endian has the simple semantic of taking the lower 32bit word, but on big-endian powerpc it takes the upper 32bits of the 64bit datum, which is going to result in a 0 length for the usual print requests this was probably visible as a gcc warning
I can confirm that Herbert's patch fixes the printing problem: * 32-bit PPC * gtk+-2.12.1 * Fedora FC8 -Joseph
2007-11-22 Matthias Clasen <mclasen@redhat.com> * modules/printbackends/cups/gtkcupsutils.c: Fix a casting problem. (#485662, patch by Herbert Valerio Riedel)