ssl "error reading the headers"

[Robert Grey]

Binary package hint: apache2

I'm getting irregular "error reading the headers" error messages when using basic authentication over SSL on apache2 "2.2.14-5ubuntu8" on ubuntu 10.04. I enabled dumpio and it looks like the "Authorization" header is getting truncated. For example, the first item is a successful "GET" with authorization:

[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in (data-TRANSIENT): 29 bytes
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in (data-TRANSIENT): GET /dist/test.txt HTTP/1.1\r\n
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in (data-TRANSIENT): 26 bytes
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in (data-TRANSIENT): Host: <removed>\r\n
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in (data-TRANSIENT): 27 bytes
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in (data-TRANSIENT): Accept-Encoding: identity\r\n
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in (data-TRANSIENT): 35 bytes
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in (data-TRANSIENT): Authorization: Basic bWU6ZG9iaWU=\r\n
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in (data-TRANSIENT): 2 bytes
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in (data-TRANSIENT): \r\n
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in [eatcrlf-nonblocking] 0 readbytes
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in - 70023

and the second failed example:

[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in (data-TRANSIENT): 29 bytes
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in (data-TRANSIENT): GET /dist/test.txt HTTP/1.1\r\n
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in (data-TRANSIENT): 26 bytes
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in (data-TRANSIENT): Host: <removed>\r\n
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in (data-TRANSIENT): 27 bytes
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in (data-TRANSIENT): Accept-Encoding: identity\r\n
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in (data-TRANSIENT): 8 bytes
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in (data-TRANSIENT): 9iaWU=\r\n
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in (data-TRANSIENT): 3 bytes
[Wed Jun 16 14:14:55 2010] [notice] mod_dumpio: dumpio_in (data-TRANSIENT): =\r\n

You can notice the "9iaWU=" is the truncated end of the correct "Authorization: Basic bWU6ZG9iaWU=" header transmitted in the successful request. This doesn't happen on a non-TSL/SSL port.

lsb_release -rd
Description: Ubuntu 10.04 LTS
Release: 10.04

apt-cache policy apache2
apache2:
  Installed: 2.2.14-5ubuntu8
  Candidate: 2.2.14-5ubuntu8
  Version table:
 *** 2.2.14-5ubuntu8 0
        500 http://us.archive.ubuntu.com/ubuntu/ lucid/main Packages
        100 /var/lib/dpkg/status

apt-cache policy openssl
openssl:
  Installed: 0.9.8k-7ubuntu8
  Candidate: 0.9.8k-7ubuntu8
  Version table:
 *** 0.9.8k-7ubuntu8 0
        500 http://us.archive.ubuntu.com/ubuntu/ lucid/main Packages
        100 /var/lib/dpkg/status

[Robert Grey (rgrey)]

I found a similar posting here:

http://serverfault.com/questions/150976/problems-serving-svn-over-https-on-ubuntu-10-04

[Robert Grey (rgrey)]

here is a python script I use to force the error:

import base64, httplib

base64string = base64.encodestring('%s:%s' % ("<uname>", "<password>"))[:-1]
headers = { "Authorization" : "Basic %s" % base64string }
while 1:
    conn = httplib.HTTPSConnection("<host>")
    conn.request("GET", "/dist/test.txt", headers=headers)
    response = conn.getresponse()
    try:
        if response.status != 200:
            print response.getheaders(), response.read()
            break
        else: print "OK"
    finally: conn.close()

hope it helps

[Ralf Hildebrandt (ralf-hildebrandt)]

This seems to be related to my bug https://bugs.launchpad.net/bugs/589611

Are you also using DEFLATE?

[Stefan Fritsch (sf-sfritsch)]

Robert, please try if deinstalling libc6-i686 or moving /lib/i686 away helps. If yes, please post your /proc/cpuinfo.

See my comment in bug #589611 for an explanation.

[Robert Grey (rgrey)]

I had the deflate module activated, but removing /etc/apache2/mods-enabled/deflate.* and restarting apache did not fix the problem.

[Robert Grey (rgrey)]

I moved /lib/i686 to /lib/i686.old and restarted apache. Did not fix the problem. Here is /proc/cpuinfo (this is on linode):

processor : 0
vendor_id : GenuineIntel
cpu family : 6
model : 23
model name : Intel(R) Xeon(R) CPU L5420 @ 2.50GHz
stepping : 6
cpu MHz : 2500.086
cache size : 6144 KB
fdiv_bug : no
hlt_bug : no
f00f_bug : no
coma_bug : no
fpu : yes
fpu_exception : yes
cpuid level : 10
wp : yes
flags : fpu de tsc msr pae cx8 cmov pat clflush mmx fxsr sse sse2 ss ht nx constant_tsc pni ssse3 sse4_1 hypervisor
bogomips : 5000.17
clflush size : 64
cache_alignment : 64
address sizes : 38 bits physical, 48 bits virtual
power management:

processor : 1
vendor_id : GenuineIntel
cpu family : 6
model : 23
model name : Intel(R) Xeon(R) CPU L5420 @ 2.50GHz
stepping : 6
cpu MHz : 2500.086
cache size : 6144 KB
fdiv_bug : no
hlt_bug : no
f00f_bug : no
coma_bug : no
fpu : yes
fpu_exception : yes
cpuid level : 10
wp : yes
flags : fpu de tsc msr pae cx8 cmov pat clflush mmx fxsr sse sse2 ss ht nx constant_tsc pni ssse3 sse4_1 hypervisor
bogomips : 5000.17
clflush size : 64
cache_alignment : 64
address sizes : 38 bits physical, 48 bits virtual
power management:

processor : 2
vendor_id : GenuineIntel
cpu family : 6
model : 23
model name : Intel(R) Xeon(R) CPU L5420 @ 2.50GHz
stepping : 6
cpu MHz : 2500.086
cache size : 6144 KB
fdiv_bug : no
hlt_bug : no
f00f_bug : no
coma_bug : no
fpu : yes
fpu_exception : yes
cpuid level : 10
wp : yes
flags : fpu de tsc msr pae cx8 cmov pat clflush mmx fxsr sse sse2 ss ht nx constant_tsc pni ssse3 sse4_1 hypervisor
bogomips : 5000.17
clflush size : 64
cache_alignment : 64
address sizes : 38 bits physical, 48 bits virtual
power management:

processor : 3
vendor_id : GenuineIntel
cpu family : 6
model : 23
model name : Intel(R) Xeon(R) CPU L5420 @ 2.50GHz
stepping : 6
cpu MHz : 2500.086
cache size : 6144 KB
fdiv_bug : no
hlt_bug : no
f00f_bug : no
coma_bug : no
fpu : yes
fpu_exception : yes
cpuid level : 10
wp : yes
flags : fpu de tsc msr pae cx8 cmov pat clflush mmx fxsr sse sse2 ss ht nx constant_tsc pni ssse3 sse4_1 hypervisor
bogomips : 5000.17
clflush size : 64
cache_alignment : 64
address sizes : 38 bits physical, 48 bits virtual
power management:

[recvfrom (recvfrom)]

Any update on this? This problem is killing us. If this truly is related to https://bugs.launchpad.net/bugs/589611 has anyone tried to reproduce this on 64-bit Lucid (since that problem seems to have affected only the 32-bit version)? If a solution is not coming soon, we need to move to another platform, Ubuntu or not. Any news will be appreciated!!!

[Robert Grey (rgrey)]

I moved to lighttpd. Since the change, the problem is resolved.

[Robert Sanders (robert-sanders)]

I was having this issue, or at least the one in the Server Fault topic linked near the top - e.g .I was getting this with SVN over HTTPS w/ BASIC Auth.

I had been able to work around it by setting MaxRequestsPerChild to some lowish number like 150, as it had been affecting me intermittently. Yesterday evening ( July 21, 2010 ) I ran some updates yesterday , and the problem got a whole lot worse - it was happening on every single request. I ended up disabling all the modules I didn't actually have to have; after turning off mod_status the problem seems to have gone away. I did disable a number of other modules first, but turning off mod_status seems to be the key. I probably won't have too much time to experiment with configurations, but maybe someone with more in depth understanding of Apache2 internals can find the issue.

P.S. My configuration is: Lucid, on a 32 bit EC2 AMI (small), running on an EBS boot disk (the image from alestic.com).

[Jiří Engelthaler (engycz)]

Maybe I found a solution (bug in memcpy routine) Bug #609290

[Launchpad Janitor (janitor)]

This bug was fixed in the package apache2 - 2.2.16-1ubuntu1

---------------
apache2 (2.2.16-1ubuntu1) maverick; urgency=low

  * Merge from debian unstable. Remaining changes:
    - debian/{control, rules}: Enable PIE hardening.
    - debian/{control, rules, apache2.2-common.ufw.profile}: Add ufw profiles.
    - debian/control: Add bzr tag and point it to our tree.
    - debian/apache2-2.common.apache2.init: Add graceful restart (LP: #456381)

apache2 (2.2.16-1) unstable; urgency=medium

  * Urgency medium for security fix.
  * New upstream release:
    - CVE-2010-1452: mod_dav, mod_cache: Fix denial of service vulnerability
      due to incorrect handling of requests without a path segment.
    - mod_dir: add FallbackResource directive, to enable admin to specify
      an action to happen when a URL maps to no file, without resorting
      to ErrorDocument or mod_rewrite
  * Fix mod_ssl header line corruption because of using memcpy for overlapping
    buffers. PR 45444. LP: #609290, #589611, #595116

apache2 (2.2.15-6) unstable; urgency=low

  * Fix init script not correctly killing htcacheclean. Closes: #580971
  * Add a separate entry in README.Debian about the need to use apache2ctl
    for starting instead of calling apache2 directly. Closes: #580445
  * Fix debug info to allow gdb loading it automatically. Closes: #581514
  * Fix install target in Makefile created by apxs2 -n. Closes: #588787
  * Fix ab sending more requests than specified by the -n parameter.
    Closes: #541158
  * Add apache2 monit configuration to apache2.2-commons examples dir.
    Closes: #583127
  * Build as PIE, since gdb in squeeze now supports it.
  * Update the postrm script to also purge the version of /var/www/index.html
    introduced in 2.2.11-7.
  * Bump Standards-Version (no changes).
 -- Chuck Short <email address hidden> Mon, 26 Jul 2010 20:21:37 +0100

[Andre van der Elst (andre-finalist)]

Does anyone know if this will also be fixed in 10.04.1 LTS scheduled for August ? Or should I attempt an upgrade to Maverick when it is released ?

[Martin Pitt (pitti)]

Accepted apache2 into lucid-proposed, the package will build now and be available in a few hours. Please test and give feedback here. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Thank you in advance!

[Robert Grey (rgrey)]

Confirmed fixed in maverick.

[Bart Vanbrabant (bart-vanbrabant)]

The packages still have not appeared in proposed. Do you have an ETA on this? We are struggling with this!

[Jean-Baptiste Lallement (jibel)]

apparently apache2 2.2.14-5ubuntu8.1 failed to build for the following reason
applying patch upstream-fix-for-lp-609290.patch to ./ ...diff: httpd-2.2.14.orig//modules/ssl/ssl_engine_io.c: No such file or directory
diff: httpd-2.2.14//modules/ssl/ssl_engine_io.c: No such file or directory
/build/buildd/apache2-2.2.14/debian/patches/upstream-fix-for-lp-609290.patch: line 2: ---: command not found
/build/buildd/apache2-2.2.14/debian/patches/upstream-fix-for-lp-609290.patch: line 3: +++: command not found
/build/buildd/apache2-2.2.14/debian/patches/upstream-fix-for-lp-609290.patch: line 4: @@: command not found
/build/buildd/apache2-2.2.14/debian/patches/upstream-fix-for-lp-609290.patch: line 5: ABOUT_APACHE: command not found
/build/buildd/apache2-2.2.14/debian/patches/upstream-fix-for-lp-609290.patch: line 21: syntax error near unexpected token `('
/build/buildd/apache2-2.2.14/debian/patches/upstream-fix-for-lp-609290.patch: line 21: `- memcpy(in, buffer->value, inl);'
 failed.
make: *** [patch-stamp] Error 1
dpkg-buildpackage: error: debian/rules build gave error exit status 2

[Bart Vanbrabant (bart-vanbrabant)]

I patched the lucid source package myself using the patch that Fedora uses. This one builds on amd64. Have not tried other arches.

[Jean-Baptiste Lallement (jibel)]

apache2 2.2.14-5ubuntu8.2 is available. Could you please enable -proposed and try it ? Thanks in advance.

[Lars Hvile (lars-fovea)]

I'm still getting the same error, at about the same rate...

apache2ctl fullstatus
                       Apache Server Status for localhost
   Server Version: Apache/2.2.14 (Ubuntu) mod_ssl/2.2.14 OpenSSL/0.9.8k
   Server Built: Aug 19 2010 03:21:20
....

from error.log
[Fri Aug 20 15:41:53 2010] [error] [client xxxxx] request failed: error reading the headers, referer: xxxx
[Fri Aug 20 15:43:01 2010] [error] [client xxxxx] request failed: error reading the headers, referer: xxxx

[Benjie Gillam (benjie)]

I have done the following updates to -proposed over a fresh install of Ubuntu server 10.04.1 (32-bit, hosted on Amazon EC2)

apache2-mpm-worker upgraded from version 2.2.14-5ubuntu8 to version 2.2.14-5ubuntu8.2
apache2.2-bin upgraded from version 2.2.14-5ubuntu8 to version 2.2.14-5ubuntu8.2
apache2.2-common upgraded from version 2.2.14-5ubuntu8 to version 2.2.14-5ubuntu8.2
libssl0.9.8 upgraded from version 0.9.8k-7ubuntu8 to version 0.9.8k-7ubuntu8.1

I'm still getting the issues (SSL+SVN+Basic Auth):

svn: Commit failed (details follow):
svn: Server sent unexpected return value (400 Bad Request) in response to OPTIONS request for 'https://svn.[SNIPPED]'

From the apache2 error log:

[Mon Aug 23 14:03:46 2010] [error] [client {IP_ADDRESS_ONE}] request failed: error reading the headers
[Mon Aug 23 14:04:04 2010] [error] [client {IP_ADDRESS_TWO}] Invalid method in request ction-set/></D:options>OPTIONS /svn_[SNIPPED] HTTP/1.1
[Mon Aug 23 14:04:31 2010] [error] [client {IP_ADDRESS_TWO}] Invalid method in request ction-set/></D:options>OPTIONS /svn_[SNIPPED] HTTP/1.1

Hopefully my [SNIPPED] etc doesn't disguise the important parts?

[Jiří Engelthaler (engycz)]

2.2.14-5ubuntu8.2 doesn't contain fix for this bug.

[Alex (akruth)]

Does there anything happen? This bug is a pain in daily work...

[Jiří Engelthaler (engycz)]

Yes. Fixing this bug is next in queue. See https://bugs.launchpad.net/ubuntu/lucid/+source/apache2/+bug/589611

[James Gregory-Monk (jamgregory)]

Any idea when this bug is due to be fixed?

[Martin Pitt (pitti)]

Accepted apache2 into lucid-proposed, the package will build now and be available in a few hours. Please test and give feedback here. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Thank you in advance!

[Eric Swenson (eric-swenson)]

I see 2.2.14-5ubuntu8.3 in lucid-proposed. Is this the version with the fix?

[Jean-Baptiste Lallement (jibel)]

@Eric, apache2 2.2.14-5ubuntu8.3 in lucid-proposed is the version to test. Thank you for helping.

[[e-mail] (tomg7373)]

Confirmed the fix - we no longer see any errors saying " request failed: error reading the headers" - and all the web pages work as expected. I searched the internet for weeks looking for that message, and failed, until I added ubuntu to the search - and found this thread - this was a huge fix for us - thank you.

For anyone looking to fix the same issue, here are the steps I used:

echo "deb http://archive.ubuntu.com/ubuntu/ lucid-proposed restricted main multiverse universe" >> /etc/apt/sources.list

cat > /etc/apt/preferences
Package: *
Pin: release a=lucid-security
Pin-Priority: 990

Package: *
Pin: release a=lucid-updates
Pin-Priority: 900

Package: *
Pin: release a=lucid-proposed
Pin-Priority: 400

(control-D to end)

Then
aptitude install apache2/lucid-proposed

Don't pick the first solution, but instead pick the following one:

Upgrade the following packages:
apache2-mpm-worker [2.2.14-5ubuntu8.2 (lucid-updates, lucid-security, now) -> 2.2.14-5ubuntu8.3 (lucid-proposed)]
apache2-threaded-dev [2.2.14-5ubuntu8.2 (lucid-updates, lucid-security, now) -> 2.2.14-5ubuntu8.3 (lucid-proposed)]
apache2.2-bin [2.2.14-5ubuntu8.2 (lucid-updates, lucid-security, now) -> 2.2.14-5ubuntu8.3 (lucid-proposed)]
apache2.2-common [2.2.14-5ubuntu8.2 (lucid-updates, lucid-security, now) -> 2.2.14-5ubuntu8.3 (lucid-proposed)]

Score is 53

Then the install will show:

The following packages will be upgraded:
  apache2 apache2-mpm-worker apache2-threaded-dev apache2.2-bin apache2.2-common

Now be sure you have the right stuff:

root@ubuntu:/etc/apt# dpkg -l | grep apach
ii apache2 2.2.14-5ubuntu8.3 Apache HTTP Server metapackage
ii apache2-mpm-worker 2.2.14-5ubuntu8.3 Apache HTTP Server - high speed threaded model
ii apache2-threaded-dev 2.2.14-5ubuntu8.3 Apache development headers - threaded MPM
ii apache2-utils 2.2.14-5ubuntu8.2 utility programs for webservers
ii apache2.2-bin 2.2.14-5ubuntu8.3 Apache HTTP Server common binary files
ii apache2.2-common 2.2.14-5ubuntu8.3 Apache HTTP Server common files

If you see 8.3, then you have the new code... Thanks again.

[Launchpad Janitor (janitor)]

This bug was fixed in the package apache2 - 2.2.14-5ubuntu8.3

---------------
apache2 (2.2.14-5ubuntu8.3) lucid-proposed; urgency=low

  * debian/apache2.2-common.postinst: Don't fail if you can load the reqtimeout module.
    (LP: #621837)
  * debian/patches/Backport fix for upstream bug PR 45444: https://issues.apache.org/bugzilla/show_bug.cgi?id=45444. (LP: #609290, #589611, #595116)
 -- Chuck Short <email address hidden> Mon, 27 Sep 2010 14:06:57 -0400

[Jan K. (jan-launchpad-kantert)]

Fix works for us too!