High loads and failure due to mod_gnutls

[Simon Josefsson]

john doe <couickie at gmail.com> writes:

> 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've seen this too, especially in high-load scenarios, but for me it
always appeared to be related to the 'GnuTLSCache dbm' setting.  Maybe
you could try changing /etc/apache2/mods-enabled/gnutls.conf to use
'GnuTLSCache none none' to see if the problem goes away?

Maybe someone on the mod_gnutls list knows more.

/Simon

> 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.