High loads and failure due to mod_gnutls

[john doe]

Hello,

I am using Apache 2.2.9 and mod_gnutls.so (GNUTLS version 1_4) and I
have experienced high load values on my server (HTTP/HTTPS Reverse
proxy running on Lenny).

Regularly a new apache2 process spawns on the `top` command and takes
X% of the CPU, if there is a single bugged process X=100, if there are
2 X=50 etc...
`w' command reported a load value of 27 this morning, after a restart
of apache it went down to 0 again. After 2 hours the load is now at 2.

I am not used to troubleshooting but I managed to get a backtrace with
gdb, here is the output:

#0  0xb7f78a0e in apr_bucket_free () from /usr/lib/libaprutil-1.so.0
#1  0x08078dac in ap_core_output_filter ()
#2  0xb75133d3 in mgs_transport_write () from
/usr/lib/apache2/modules/mod_gnutls.so
#3  0xb78b93f2 in _gnutls_io_write_buffered () from /usr/lib/libgnutls.so.26
#4  0xb78b9950 in _gnutls_io_write_flush () from /usr/lib/libgnutls.so.26
#5  0xb78b5dc0 in _gnutls_send_int () from /usr/lib/libgnutls.so.26
#6  0xb78b627b in gnutls_record_send () from /usr/lib/libgnutls.so.26
#7  0xb7513b09 in mgs_filter_output () from
/usr/lib/apache2/modules/mod_gnutls.so
#8  0x0806f10e in ap_content_length_filter ()
#9  0xb74e07fc in ?? () from /usr/lib/apache2/modules/mod_proxy_http.so
#10 0x08407b98 in ?? ()
#11 0x084223a0 in ?? ()
#12 0x084223a0 in ?? ()
#13 0x00000001 in ?? ()
#14 0x00002000 in ?? ()
#15 0x00000000 in ?? ()

I sent a interrupt signal to the process and then ended up in a sort
of fatal error function from gnu_tls (I cannot recall the name).
Maybe some function in gnu_tls is looping forever, waiting for a right
return value (that never come unfortunately).

Here are some other debugging clues:


PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
5269 www-data  20   0 15136 5516 2424 R 49.8  0.4  15:53.62 apache2
5314 www-data  20   0 15012 5296 2308 R 47.8  0.4  10:55.86 apache2

load average: 1.50, 1.80, 1.68

This output is redundant in apache error log:

[Wed Oct 28 15:54:44 2009] [debug] proxy_util.c(1819): proxy: worker
proxy:reverse already initialized
[Wed Oct 28 15:54:44 2009] [debug] proxy_util.c(1913): proxy:
initialized single connection worker 17 in child 5461 for (*)
=====================================================================================
[Wed Oct 28 15:48:33 2009] [info] [client 62.36.240.2] (104)Connection
reset by peer: core_output_filter: writing data to the network
[Wed Oct 28 15:49:40 2009] [info] [client 193.203.96.2] (32)Broken
pipe: core_output_filter: writing data to the network
[Wed Oct 28 15:53:59 2009] [info] [client 193.203.96.2] (32)Broken
pipe: core_output_filter: writing data to the network


I may not be able to give you more information about this server, the
load was high but there were no latency.
Do you have an idea about this issue ?

Thank you for your attention.
Regards.