This service will be undergoing maintenance at 00:00 UTC, 2017-10-23 It is expected to last about 30 minutes
Bug 831589 - httpd with mod_nss returns Bad Request
httpd with mod_nss returns Bad Request
Status: CLOSED ERRATA
Product: Fedora
Classification: Fedora
Component: mod_nss (Show other bugs)
17
Unspecified Unspecified
unspecified Severity high
: ---
: ---
Assigned To: Matthew Harmsen
Fedora Extras Quality Assurance
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2012-06-13 07:33 EDT by Martin Kosek
Modified: 2012-06-19 10:52 EDT (History)
3 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2012-06-19 10:52:22 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
nss.conf (8.63 KB, text/plain)
2012-06-13 07:35 EDT, Martin Kosek
no flags Details
Server-Cert used for mod_nss (3.84 KB, text/plain)
2012-06-13 07:36 EDT, Martin Kosek
no flags Details
Configuration for mod_wsgi (49 bytes, text/plain)
2012-06-13 07:37 EDT, Martin Kosek
no flags Details
Simple WSGI script used for reproduction (557 bytes, text/plain)
2012-06-13 07:38 EDT, Martin Kosek
no flags Details
httpd error_log (281.82 KB, text/plain)
2012-06-13 07:42 EDT, Martin Kosek
no flags Details

  None (edit)
Description Martin Kosek 2012-06-13 07:33:31 EDT
Description of problem:
When I configure httpd with mod_wsgi+mod_nss, httpd _sometimes_ returns "400 Bad Request" to legitimate requests sent to the secured index page:

-----------------------------
Bad Request

Your browser sent a request that this server could not understand.
Request header field is missing ':' separator.

86_64;
-----------------------------


Output from Firefox firebug:

Request Headers
Accept	text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Accept-Encoding	gzip, deflate
Accept-Language	es,en-us;q=0.7,en;q=0.3
Cache-Control	max-age=0
Connection	keep-alive
Host	vm-131.idm.lab.bos.redhat.com
User-Agent	Mozilla/5.0 (X11; Linux x86_64; rv:13.0) Gecko/20100101 Firefox/13.0

Response Headers
Connection	close
Content-Length	394
Content-Type	text/html; charset=iso-8859-1
Date	Wed, 13 Jun 2012 11:21:51 GMT
Server	Apache/2.2.22 (Fedora)

Response body:
<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html><head>
<title>400 Bad Request</title>
</head><body>
<h1>Bad Request</h1>
<p>Your browser sent a request that this server could not understand.<br />
Request header field is missing ':' separator.<br />
<pre>
86_64;</pre>
</p>
<hr>
<address>Apache/2.2.22 (Fedora) Server at vm-131.idm.lab.bos.redhat.com Port 443</address>
</body></html>


It seems to me that httpd gets to this state right after I "service httpd reload" it.

Version-Release number of selected component (if applicable):
httpd-2.2.22-4.fc17.x86_64
mod_nss-1.0.8-16.fc17.x86_64
mod_wsgi-3.3-2.fc17.x86_64

How reproducible:

Steps to Reproduce:
1. Install httpd, mod_nss, mod_wsgi
2. Generate Server-Cert in /etc/httpd/alias
3. Set up a WSGI script (you can use the one I attached)
4) Restart/reload apache and try several requests
  
Actual results:
httpd returns Bad Request for some requests

Expected results:
httpd always returns requested page
Comment 1 Martin Kosek 2012-06-13 07:35:57 EDT
Created attachment 591446 [details]
nss.conf
Comment 2 Martin Kosek 2012-06-13 07:36:51 EDT
Created attachment 591449 [details]
Server-Cert used for mod_nss
Comment 3 Martin Kosek 2012-06-13 07:37:32 EDT
Created attachment 591450 [details]
Configuration for mod_wsgi
Comment 4 Martin Kosek 2012-06-13 07:38:09 EDT
Created attachment 591451 [details]
Simple WSGI script used for reproduction
Comment 5 Martin Kosek 2012-06-13 07:42:49 EDT
Created attachment 591453 [details]
httpd error_log
Comment 6 Martin Kosek 2012-06-13 08:02:21 EDT
I tested the failing httpd with another SSL provider (mod_ssl) and this issue did not occur, i.e. I really think this must be in mod_nss.
Comment 7 Martin Kosek 2012-06-15 03:23:59 EDT
I used httpd's dumpio module to track what is being sent to apache from SSL filter and it is indeed wrong:


[Fri Jun 15 03:18:02 2012] [info] Connection to child 0 established (server vm-091.idm.lab.bos.redhat.com:443, client 10.16.78.91)
[Fri Jun 15 03:18:02 2012] [debug] mod_dumpio.c(113): mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Fri Jun 15 03:18:02 2012] [debug] mod_dumpio.c(55): mod_dumpio:  dumpio_in (data-TRANSIENT): 32 bytes
[Fri Jun 15 03:18:02 2012] [debug] mod_dumpio.c(74): mod_dumpio:  dumpio_in (data-TRANSIENT): POST /ipa/session/xml HTTP/1.1\r\n
[Fri Jun 15 03:18:02 2012] [debug] mod_dumpio.c(113): mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Fri Jun 15 03:18:02 2012] [debug] mod_dumpio.c(55): mod_dumpio:  dumpio_in (data-TRANSIENT): 37 bytes
[Fri Jun 15 03:18:02 2012] [debug] mod_dumpio.c(74): mod_dumpio:  dumpio_in (data-TRANSIENT): Host: vm-091.idm.lab.bos.redhat.com\r\n
[Fri Jun 15 03:18:02 2012] [debug] mod_dumpio.c(113): mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Fri Jun 15 03:18:02 2012] [debug] mod_dumpio.c(55): mod_dumpio:  dumpio_in (data-TRANSIENT): 23 bytes
[Fri Jun 15 03:18:02 2012] [debug] mod_dumpio.c(74): mod_dumpio:  dumpio_in (data-TRANSIENT): Accept-Encoding: gzip\r\n
[Fri Jun 15 03:18:02 2012] [debug] mod_dumpio.c(113): mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Fri Jun 15 03:18:02 2012] [debug] mod_dumpio.c(55): mod_dumpio:  dumpio_in (data-TRANSIENT): 24 bytes
[Fri Jun 15 03:18:02 2012] [debug] mod_dumpio.c(74): mod_dumpio:  dumpio_in (data-TRANSIENT): Accept-Language: en-us\r\n
[Fri Jun 15 03:18:02 2012] [debug] mod_dumpio.c(113): mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Fri Jun 15 03:18:02 2012] [debug] mod_dumpio.c(55): mod_dumpio:  dumpio_in (data-TRANSIENT): 56 bytes
[Fri Jun 15 03:18:02 2012] [debug] mod_dumpio.c(74): mod_dumpio:  dumpio_in (data-TRANSIENT): Referer: https://vm-091.idm.lab.bos.redhat.com/ipa/   xml\r\n
[Fri Jun 15 03:18:02 2012] [debug] mod_dumpio.c(113): mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Fri Jun 15 03:18:02 2012] [debug] mod_dumpio.c(55): mod_dumpio:  dumpio_in (data-TRANSIENT): 83 bytes
[Fri Jun 15 03:18:02 2012] [debug] mod_dumpio.c(74): mod_dumpio:  dumpio_in (data-TRANSIENT): Cookie: ipa_session=951ed824da5dbaaae008c129c41fd969; httponly; Path=/ipa; secure\r\n
[Fri Jun 15 03:18:02 2012] [debug] mod_dumpio.c(113): mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Fri Jun 15 03:18:02 2012] [debug] mod_dumpio.c(55): mod_dumpio:  dumpio_in (data-TRANSIENT): 28 bytes
[Fri Jun 15 03:18:02 2012] [debug] mod_dumpio.c(74): mod_dumpio:  dumpio_in (data-TRANSIENT): boolean>0</boolean></value>\n
[Fri Jun 15 03:18:02 2012] [debug] mod_dumpio.c(113): mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Fri Jun 15 03:18:02 2012] [debug] mod_dumpio.c(55): mod_dumpio:  dumpio_in (data-TRANSIENT): 10 bytes
[Fri Jun 15 03:18:02 2012] [debug] mod_dumpio.c(74): mod_dumpio:  dumpio_in (data-TRANSIENT): </member>\n
[Fri Jun 15 03:18:02 2012] [debug] protocol.c(800): [client 10.16.78.91] Request header field is missing ':' separator: boolean>0</boolean></       value>, referer: https://vm-091.idm.lab.bos.redhat.com/ipa/xml

It seems that some data are missing - it returned:
(data-TRANSIENT): Cookie: ipa_session=951ed824da5dbaaae008c129c41fd969; httponly; Path=/ipa; secure\r\n

And then it missed some data and returned:
(data-TRANSIENT): boolean>0</boolean></value>\n
Comment 8 Fedora Update System 2012-06-15 11:44:46 EDT
mod_nss-1.0.8-17.fc17 has been submitted as an update for Fedora 17.
https://admin.fedoraproject.org/updates/mod_nss-1.0.8-17.fc17
Comment 9 Fedora Update System 2012-06-15 19:54:53 EDT
Package mod_nss-1.0.8-17.fc17:
* should fix your issue,
* was pushed to the Fedora 17 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing mod_nss-1.0.8-17.fc17'
as soon as you are able to.
Please go to the following url:
https://admin.fedoraproject.org/updates/FEDORA-2012-9514/mod_nss-1.0.8-17.fc17
then log in and leave karma (feedback).
Comment 10 Fedora Update System 2012-06-19 10:52:22 EDT
mod_nss-1.0.8-17.fc17 has been pushed to the Fedora 17 stable repository.  If problems still persist, please make note of it in this bug report.

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