On Mon, 16 Dec 2019 02:37:50 +0100 =?UTF-8?Q?Bernhard_=c3=9cbelacker?= <bernha...@mailbox.org> wrote: > Dear Maintainer, > tried to reconstruct the given backtrace with debug symbols > in a gdb session and came to following, maybe it could be > of some help. > (Still a proper backtrace with dbgsym packages > installed would be better.) > > Kind regards, > Bernhard > >
Dear Maintainer: I came across this bugs too. The problem is a infinite loop between mod-reqtimeout and mod-gnutls. The mod-gnutls (and underlaying gnutls) tries to read some bytes when the client hasn't sent any (like an empty tcp conn) and the mod-reqtimeout returns a timeout, causing mod-gnutls to loop endless trying to read more. Either mod-reqtimeout is broken, or either mod-gnutls doesn't handle correctly the timeouts. After debugging a lot with gdb, I can reconstruct the loop as follow: The code starts at function gnutls_io_input_read from gnutls_io.c from mod_gnutls, line 246, the "while(1)" loop. The code calls gnutls_record_recv, from gnutls, which in turns calls _gnutls_recv_int. gnutls_recv_int is called with type=GNUTLS_APPLICATION_DATA asking for 8192 bytes. Next it calls check_session_status, which checks if there is an EOF, and there is NO EOF. Also, check_session_status says that the session->internals.recv_state is RECV_STATE_0, whichs makes check_session_status return 1. Next, it calls get_data_from_buffers, which returns 0, which means there is no data in the buffer to consume. Next, it calls _gnutls_recv_in_buffers. _gnutls_recv_in_buffers calls recv_headers, which tries to read the header (which is 5). it calls _gnutls_io_read_buffered for 5 bytes. _gnutls_io_read_buffered ask for 5 bytes to _gnutls_read, which in turn uses _gnutls_stream_read to complete the request. _gnutls_stream_read returns back to mod-gnutls using the "pull_func" mgs_transport_read. msg_transport_read is located at gnutls_io.c:824 mgs_transport_read tries to use ap_get_brigade to get some bytes from the underlaying socket. ap_get_brigade tries to read from the "next" ap_filter_t, which (in my case) is "reqtimeout". reqtimeout_filter function calls check_time_left, which returns APR_TIMEUP. When it returns APR_TIMEUP, it logs "Request %s read timeout". So, back to mgs_transport_read, it reads APR_TIMEUP from the ap_get_brigade. BUT, it handles wrong this timeout and converts it to EAGAIN, which makes this whole stack run back. This is a big, 'nice' nasty bug, I have to say. As a workout around, I disabled module reqtimeout. Seems to solve the cpu usage issue. But, the bug is way more big than 'disabling' reqtimeout. Because, the problem is between mod-gnutls and mod-reqtimeout Steps to reproduce: Enable apache2 with the modules mod-gnutls, and mod-reqtimeout. Setup a reqtimeout like: RequestReadTimeout header=20-40,minrate=500 and open an openssl s_client: openssl s_client -connect IP:port Don't send any data over the openssl connect. Just wait for the timeout to happen. After the timeout, the CPU usage will increase. Also, you can quit the openssl s_client and the apache process will be stuck in the endless loop. -- Atte. Félix Arreola Firmado con GPG 0x1e249ee4
pgpRhuwCqo6hD.pgp
Description: Firma digital OpenPGP
