Bug 816591 - Network print via cups fails - error_log contains garbage "Bad request line" and "Bad URI"
Network print via cups fails - error_log contains garbage "Bad request line" ...
Status: CLOSED DUPLICATE of bug 787884
Product: Red Hat Enterprise Linux 6
Classification: Red Hat
Component: cups (Show other bugs)
x86_64 Linux
unspecified Severity unspecified
: rc
: ---
Assigned To: Tim Waugh
Depends On:
  Show dependency treegraph
Reported: 2012-04-26 09:15 EDT by devurandom
Modified: 2012-05-07 04:40 EDT (History)
2 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Last Closed: 2012-05-02 12:21:36 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---

Attachments (Terms of Use)
Sample line from error_log (115 bytes, text/plain)
2012-04-26 09:15 EDT, devurandom
no flags Details
cupsd.conf (3.17 KB, text/plain)
2012-04-26 09:16 EDT, devurandom
no flags Details

  None (edit)
Description devurandom 2012-04-26 09:15:52 EDT
Created attachment 580469 [details]
Sample line from error_log

Description of problem:
When we try to print from a Fedora 16 or SL 6.2 machine on a CUPS server (config attached) running on a SL 6.2 server the print will fail in various ways (both examples from a SL 6.2 client accessed via ssh -X):

Using okular:
Okular will hang when selecting File/Print and ask for a password on the terminal it was started from. The cups server will log several lines similar to:
E ... Bad request line "<garbage>" from <my ip>"!
E ... Bad URI "<garbage>" in request!

Using evince:
Evince will show the list of printers, ask for the authentication details and everything appears normal. But the error_log of the cups server will show lines similar to the ones above, just this time they will continuously appear until the print dialogue is closed. After pressing "print", the file will not actually be printed, but is shown as "processing" in the cups job list instead. Cancelling the job keeps it in the job list as "cancelled" and does not remove it or allow other jobs to be printed.

The <garbage> part in the log will always start with the same 4 characters - see the attached file for a sample.

The effect does not depend on which file is being opened by evince or okular.

Version-Release number of selected component (if applicable):
cups-1.4.2-44.el6.x86_64 (on the cups server)
evince-2.28.2-14.el6_0.1.x86_64 (on the client)
kdegraphics-4.3.4-6.el6.x86_64 (on the client)

How reproducible:
Open the file using okular or evince and select File/Print from the menu.
Comment 1 devurandom 2012-04-26 09:16:45 EDT
Created attachment 580471 [details]
Comment 3 devurandom 2012-04-27 04:05:00 EDT
It appears this has something to do with acroread trying to print and breaking the whole cups server in that process.

The current workaround we have is as follows:
1) Cancel the offending print jobs (which will never be completed)
2) Restart the cups service *twice*
3) Restart the printer
Comment 4 Tim Waugh 2012-04-30 10:35:47 EDT
You've attached cupsd.conf but not /var/log/cups_error_log.

Please attach a /var/log/cups/error_log that contains these lines.
Comment 5 devurandom 2012-04-30 12:55:02 EDT
I have attached "Sample line from error_log". Since I do not know what information is contained in the log, I am hesitant to publicly post the complete file. May I send it to you in private?
Comment 6 Tim Waugh 2012-05-01 06:04:53 EDT
Yes, please do.  Thanks.
Comment 7 Tim Waugh 2012-05-02 12:21:36 EDT
This looks like it is a duplicate of bug #787884.

*** This bug has been marked as a duplicate of bug 787884 ***
Comment 8 Jiri Popelka 2012-05-04 06:48:48 EDT
Tim, are you sure this is a duplicate of bug #787884 ?
The cupsd.conf in comment #1 shows there's no encryption used (unlike in bug #787884). Also the latest comment in STR #3288 (which seems to be similar to bug #787884) shows that the problem could be somewhere in the encryption area.
Comment 9 Tim Waugh 2012-05-04 10:59:15 EDT
There is encryption in use for the connections that fail (all of them in the supplied log).

The way it happens is:

client is accepted, and it sends "OPTIONS * HTTP/1.1".  Following that, the connection enters encrypted mode.

Next there is a "POST / HTTP/1.1" but with no authentication data.  Accordingly, the server sends 'WWW-Authenticate: Basic realm="CUPS"' and closes the connection.

However, immediately after that we get a "Bad request line" log message for that same client, followed by another call to cupsdCloseClient (i.e. it ends up being called twice for the same client).

devurandom@gmx.net: it might help us if you could attach the /etc/cups/client.conf file (or else ~/.cups/client.conf) from the client machine.
Comment 10 devurandom 2012-05-07 04:40:10 EDT
(In reply to comment #9)
> devurandom@gmx.net: it might help us if you could attach the
> /etc/cups/client.conf file (or else ~/.cups/client.conf) from the client
> machine.
$ ll /etc/cups/client.conf 
-rw-r--r--. 1 root lp 0 Mar 29 13:35 /etc/cups/client.conf
$ cat ~/.cups/client.conf 
ServerName print

Note You need to log in before you can comment on or make changes to this bug.