https://bz.apache.org/bugzilla/show_bug.cgi?id=66649
Bug ID: 66649
Summary: apache http2 endless loop in h2_session_send in
httpd-2.4.55/56/57
Product: Apache httpd-2
Version: 2.4.57
Hardware: PC
OS: Linux
Status: NEW
Severity: normal
Priority: P2
Component: mod_http2
Assignee: bugs@httpd.apache.org
Reporter: dzwi...@strato.de
Target Milestone: ---
Created attachment 38589
--> https://bz.apache.org/bugzilla/attachment.cgi?id=38589&action=edit
workaround for endless loop in h2_session_send (for trunk)
Hello,
starting with the big mod_http2 update in httpd-2.4.55 we see sometimes
an endless loop using 100% of a cpu-core in h2_session.c:h2_session_send.
- the endless loop does not occur when the current httpd-code (httpd-2.4.57)
is used with mod_http2 from httpd-2.4.54.
- this problem seems to be independent of Bug 66646 reported here:
https://bz.apache.org/bugzilla/show_bug.cgi?id=66646. It still happens
when the bugfix from patch r1910386 is applied.
(https://svn.apache.org/viewvc?view=revision&revision=1910386)
- this problem seems also to be independent of the ngnttp2-library-version.
It still happens with the most recent nghttp2-v1.54.0 library.
- our servers are configured to run with 64 worker-threads per process,
and the machines use redhat-linux. For each server which serves about
20 million requests per day, we see it happen at most once or twice a day.
- traces show that the loop-parameters look always similar when the
situation occurs. Some data is buffered, but the loop does not make
progress anymore.
- when the loop is broken after 100k iterations with the attached workaround,
the httpd-child continues without other error messages.
see patch.
- I include a core dump for the endless-loop situation. Perhaps the
struct values can help to identify the problem.
Greetings,
Barnim
Example output with workaround:
------------------------------
[Mon Jun 12 17:58:03 2023] [error] [client ...] http2_session_send
LOOP[100001]: 0 rv: 0 pending: 0 buffered: 154393 thres: 131072 empty: 1
scratch: 0 slen: 0 unflushed: 0 written: 106818 write_size: 16384 -> stop
[Tue Jun 13 07:26:36 2023] [error] [client ...] http2_session_send
LOOP[100001]: 0 rv: 0 pending: 0 buffered: 159877 thres: 131072 empty: 1
scratch: 0 slen: 0 unflushed: 0 written: 97564 write_size: 16384 -> stop
[Wed Jun 14 21:05:47 2023] [error] [client ...] http2_session_send
LOOP[100001]: 0 rv: 0 pending: 0 buffered: 160453 thres: 131072 empty: 1
scratch: 0 slen: 0 unflushed: 0 written: 112932 write_size: 16384 -> stop
Example core (from gcore):
-------------------------
(gdb) bt
#0 0x00000000005ef868 in h2_c1_io_pending (io=0x7fbe30008770) at
h2_c1_io.c:369
#1 0x00000000005efc32 in h2_c1_io_assure_flushed
(io=io@entry=0x7fbe30008770) at h2_c1_io.c:386
#2 0x00000000005de308 in h2_session_send
(session=session@entry=0x7fbe30008730) at h2_session.c:1283
#3 0x00000000005de4a3 in h2_session_process (session=0x7fbe30008730,
async=0) at h2_session.c:1830
#4 0x00000000005cb519 in h2_c1_run (c=c@entry=0x7fbf80025c18) at h2_c1.c:130
#5 0x00000000005cb92d in h2_c1_hook_process_connection (c=0x7fbf80025c18) at
h2_c1.c:278
#6 0x00000000004dc180 in ap_run_process_connection
(c=c@entry=0x7fbf80025c18) at connection.c:42
#7 0x00000000004dc6ae in ap_process_connection (c=c@entry=0x7fbf80025c18,
csd=csd@entry=0x7fbf80025a00) at connection.c:217
#8 0x000000000082191b in process_socket (bucket_alloc=0x7fbe2c0008e8,
my_thread_num=40, my_child_num=96, sock=0x7fbf80025a00, p=0x7fbf80025978,
thd=0x1d5aca8) at worker.c:485
#9 worker_thread (thd=0x1d5aca8, dummy=<optimized out>) at worker.c:814
#10 0x00007fbfccb81ea5 in start_thread () from /lib64/libpthread.so.0
#11 0x00007fbfcc6a6b0d in clone () from /lib64/libc.so.6
(gdb) frame 2
(gdb) info locals
ngrv = 0
pending = 1
rv = 0
(gdb) p *session
$1 = {child_num = 40924, id = 12, c1 = 0x7fbf80025c18, r = 0x0, s =
0x1de0638, pool = 0x7fbe300086b8, mplx = 0x7fbe30008da0, workers = 0x1de8410,
cin = 0x0, io = {
session = 0x7fbe30008730, output = 0x7fbe2c007040, is_tls = 1, unflushed =
0, cooldown_usecs = 0, warmup_size = 1048576, write_size = 16384, last_write =
0,
bytes_read = 1209, bytes_written = 28498, buffer_output = 1, buffered_len =
131146, flush_threshold = 131072, is_flushed = 0, is_passing = 0, scratch =
0x0, ssize = 0,
slen = 0}, padding_max = 0, padding_always = 1, ngh2 = 0x7fbe2400a140,
state = H2_SESSION_ST_DONE, local = {accepted_max = 17, completed_max = 19,
emitted_count = 0,
emitted_max = 0, error = 104, error_msg = 0x0, accepting = 0, shutdown =
1}, remote = {accepted_max = 0, completed_max = 0, emitted_count = 10,
emitted_max = 19, error = 0,
error_msg = 0x0, accepting = 1, shutdown = 0}, reprioritize = 0, flush = 0,
wait_us = 0, push_diary = 0x7fbe30008ed8, monitor = 0x7fbe30008c98,
open_streams = 8,
streams_done = 2, responses_submitted = 2, streams_reset = 0, pushes_promised
= 0, pushes_submitted = 0, pushes_reset = 0, frames_received = 12, frames_sent
= 15,
max_stream_count = 100, max_stream_mem = 32768, idle_frames = 1, idle_delay =
0, bbtmp = 0x7fbe30008e98,
status = "[10/2] done: stream 19, GET /.../news/profileviewrss/foxfeed",
last_status_code = 0, last_status_msg = 0x0, input_flushed = 0, out_c1_blocked
= 0x7fbe30008938,
ready_to_process = 0x7fbe30008ae8}
(gdb) p *session.io.output
$2 = {p = 0x7fbf80025978, list = {next = 0x7fbe2c007048, prev =
0x7fbe2c007048}, bucket_alloc = 0x7fbe2c0008e8}
(gdb) p *session.ngh2
$3 = {streams = {table = 0x7fbe24008400, mem = 0x7fbe2400ab20, size = 9,
tablelen = 16, tablelenbits = 4}, root = {pq_entry = {index = 0}, obq = {q =
0x7fbe24008300,
mem = 0x7fbe2400ab20, length = 1, capacity = 4, less = 0x7d78e0
<stream_less>}, content_length = -1, recv_content_length = 0,
descendant_last_cycle = 171490, cycle = 0,
descendant_next_seq = 13, seq = 0, dep_prev = 0x0, dep_next =
0x7fbe2400b6a0, sib_prev = 0x0, sib_next = 0x0, closed_prev = 0x0, closed_next
= 0x0, stream_user_data = 0x0,
item = 0x0, last_writelen = 16375, stream_id = 0, remote_window_size = 0,
recv_window_size = 0, consumed_size = 0, recv_reduction = 0, local_window_size
= 0, weight = 16,
pending_penalty = 0, sum_dep_weight = 220, state = NGHTTP2_STREAM_IDLE,
status_code = -1, http_flags = 0, flags = 0 '\000', shut_flags = 0 '\000',
queued = 0 '\000',
window_update_queued = 0 '\000', extpri = 3 '\003', http_extpri = 3
'\003'}, ob_urgent = {head = 0x0, tail = 0x0, n = 0}, ob_reg = {head = 0x0,
tail = 0x0, n = 0}, ob_syn = {
head = 0x0, tail = 0x0, n = 0}, sched = {{ob_data = {q = 0x0, mem =
0x7fbe2400ab20, length = 0, capacity = 0, less = 0x7d8c90 <stream_less>}},
{ob_data = {q = 0x0,
mem = 0x7fbe2400ab20, length = 0, capacity = 0, less = 0x7d8c90
<stream_less>}}, {ob_data = {q = 0x0, mem = 0x7fbe2400ab20, length = 0,
capacity = 0,
less = 0x7d8c90 <stream_less>}}, {ob_data = {q = 0x0, mem =
0x7fbe2400ab20, length = 0, capacity = 0, less = 0x7d8c90 <stream_less>}},
{ob_data = {q = 0x0,
mem = 0x7fbe2400ab20, length = 0, capacity = 0, less = 0x7d8c90
<stream_less>}}, {ob_data = {q = 0x0, mem = 0x7fbe2400ab20, length = 0,
capacity = 0,
less = 0x7d8c90 <stream_less>}}, {ob_data = {q = 0x0, mem =
0x7fbe2400ab20, length = 0, capacity = 0, less = 0x7d8c90 <stream_less>}},
{ob_data = {q = 0x0,
mem = 0x7fbe2400ab20, length = 0, capacity = 0, less = 0x7d8c90
<stream_less>}}}, aob = {item = 0x7fbe240225b0, framebufs = {head =
0x7fbe24009000, cur = 0x7fbe24009000,
mem = 0x7fbe2400ab20, chunk_length = 16394, max_chunk = 4, chunk_used =
1, chunk_keep = 1, offset = 10}, state = NGHTTP2_OB_SEND_DATA}, iframe = {frame
= {hd = {length = 0,
stream_id = 0, type = 0 '\000', flags = 0 '\000', reserved = 0 '\000'},
data = {hd = {length = 0, stream_id = 0, type = 0 '\000', flags = 0 '\000',
reserved = 0 '\000'},
padlen = 0}, headers = {hd = {length = 0, stream_id = 0, type = 0
'\000', flags = 0 '\000', reserved = 0 '\000'}, padlen = 0, pri_spec =
{stream_id = 0, weight = 0,
exclusive = 0 '\000'}, nva = 0x0, nvlen = 0, cat =
NGHTTP2_HCAT_REQUEST}, priority = {hd = {length = 0, stream_id = 0, type = 0
'\000', flags = 0 '\000',
reserved = 0 '\000'}, pri_spec = {stream_id = 0, weight = 0,
exclusive = 0 '\000'}}, rst_stream = {hd = {length = 0, stream_id = 0, type = 0
'\000', flags = 0 '\000',
reserved = 0 '\000'}, error_code = 0}, settings = {hd = {length = 0,
stream_id = 0, type = 0 '\000', flags = 0 '\000', reserved = 0 '\000'}, niv =
0, iv = 0x0},
push_promise = {hd = {length = 0, stream_id = 0, type = 0 '\000', flags =
0 '\000', reserved = 0 '\000'}, padlen = 0, nva = 0x0, nvlen = 0,
promised_stream_id = 0,
reserved = 0 '\000'}, ping = {hd = {length = 0, stream_id = 0, type = 0
'\000', flags = 0 '\000', reserved = 0 '\000'}, opaque_data =
"\000\000\000\000\000\000\000"},
goaway = {hd = {length = 0, stream_id = 0, type = 0 '\000', flags = 0
'\000', reserved = 0 '\000'}, last_stream_id = 0, error_code = 0, opaque_data =
0x0,
opaque_data_len = 0, reserved = 0 '\000'}, window_update = {hd =
{length = 0, stream_id = 0, type = 0 '\000', flags = 0 '\000', reserved = 0
'\000'},
window_size_increment = 0, reserved = 0 '\000'}, ext = {hd = {length =
0, stream_id = 0, type = 0 '\000', flags = 0 '\000', reserved = 0 '\000'},
payload = 0x0}},
ext_frame_payload = {altsvc = {origin = 0x0, origin_len = 0, field_value =
0x0, field_value_len = 0}, origin = {nov = 0, ov = 0x0}, priority_update =
{stream_id = 0,
field_value = 0x0, field_value_len = 0}}, iv = 0x0, sbuf = {begin =
0x7fbe2400a4fc "\200", end = 0x7fbe2400a51c "", pos = 0x7fbe2400a4fc "\200",
last = 0x7fbe2400a4fc "\200", mark = 0x7fbe2400a505 ""}, lbuf = {begin =
0x0, end = 0x0, pos = 0x0, last = 0x0, mark = 0x0}, raw_lbuf = 0x0, niv = 0,
max_niv = 0,
payloadleft = 0, padlen = 0, state = NGHTTP2_IB_READ_HEAD, raw_sbuf =
"\200\000\000\021\222\000\000\000\023", '\000' <repeats 22 times>}, hd_deflater
= {ctx = {hd_table = {
buffer = 0x7fbe2400ac90, mask = 127, first = 18446744073709551609, len
= 7}, mem = 0x7fbe2400ab20, hd_table_bufsize = 428, hd_table_bufsize_max =
4096, next_seq = 7,
bad = 0 '\000'}, map = {table = {0x0 <repeats 21 times>, 0x7fbe24008f20,
0x0 <repeats 60 times>, 0x7fbe24022940, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0,
0x7fbe24022890,
0x0 <repeats 12 times>, 0x7fbe24012540, 0x0, 0x0, 0x0, 0x0,
0x7fbe24008ec0, 0x0 <repeats 20 times>}}, deflate_hd_table_bufsize_max = 4096,
min_hd_table_bufsize_max = 4294967295, notify_table_size_change = 0
'\000'}, hd_inflater = {ctx = {hd_table = {buffer = 0x7fbe2400b0a0, mask = 127,
first = 18446744073709551609, len = 7}, mem = 0x7fbe2400ab20,
hd_table_bufsize = 654, hd_table_bufsize_max = 4096, next_seq = 7, bad = 0
'\000'}, huff_decode_ctx = {
fstate = 16448}, namebuf = {begin = 0x7fbe24008c38 "bytes", end =
0x7fbe24008c41 "", pos = 0x7fbe24008c38 "bytes", last = 0x7fbe24008c3d "", mark
= 0x7fbe24008c38 "bytes"},
valuebuf = {begin = 0x7fbe2401c448
"/.../news/profileviewrss/foxfeedspro/2023/01/....jpg", end = 0x7fbe2401c4c1
"",
pos = 0x7fbe2401c448
"/.../news/profileviewrss/foxfeedspro/2023/01/....jpg", last = 0x7fbe2401c49c
"",
mark = 0x7fbe2401c448
"/.../news/profileviewrss/foxfeedspro/2023/01/....jpg"}, namercbuf = 0x0,
valuercbuf = 0x0, nv_name_keep = 0x0,
nv_value_keep = 0x0, left = 62, index = 61, settings_hd_table_bufsize_max =
4096, min_hd_table_bufsize_max = 4294967295, shift = 0, opcode =
NGHTTP2_HD_OPCODE_INDEXED,
state = NGHTTP2_HD_STATE_INFLATE_START, huffman_encoded = 1 '\001',
index_required = 0 '\000', no_index = 0 '\000'}, callbacks = {send_callback =
0x5da360 <send_cb>,
recv_callback = 0x0, on_frame_recv_callback = 0x5dd2e0 <on_frame_recv_cb>,
on_invalid_frame_recv_callback = 0x5dc280 <on_invalid_frame_recv_cb>,
on_data_chunk_recv_callback = 0x5da160 <on_data_chunk_recv_cb>,
before_frame_send_callback = 0x0, on_frame_send_callback = 0x5dbf50
<on_frame_send_cb>,
on_frame_not_send_callback = 0x0, on_stream_close_callback = 0x5da030
<on_stream_close_cb>, on_begin_headers_callback = 0x5daa60
<on_begin_headers_cb>,
on_header_callback = 0x5da8f0 <on_header_cb>, on_header_callback2 = 0x0,
on_invalid_header_callback = 0x5d9740 <on_invalid_header_cb>,
on_invalid_header_callback2 = 0x0,
select_padding_callback = 0x5d95b0 <select_padding_cb>,
read_length_callback = 0x0, on_begin_frame_callback = 0x0, send_data_callback =
0x5d98a0 <on_send_data_cb>,
pack_extension_callback = 0x0, unpack_extension_callback = 0x0,
on_extension_chunk_recv_callback = 0x0, error_callback = 0x0, error_callback2 =
0x0}, mem = {
mem_user_data = 0x0, malloc = 0x7ed3f0 <default_malloc>, free = 0x7ed3e0
<default_free>, calloc = 0x7ed3d0 <default_calloc>, realloc = 0x7ed3c0
<default_realloc>},
user_data = 0x7fbe30008730, closed_stream_head = 0x0, closed_stream_tail =
0x0, idle_stream_head = 0x0, idle_stream_tail = 0x0, inflight_settings_head =
0x7fbe24009610,
stream_seq = 0, num_outgoing_streams = 0, num_incoming_streams = 9,
num_incoming_reserved_streams = 0, max_incoming_reserved_streams = 200,
num_closed_streams = 0,
num_idle_streams = 0, nvbuflen = 0, obq_flood_counter_ = 0, max_outbound_ack
= 1000, max_send_header_block_length = 65536, max_settings = 32, next_stream_id
= 2,
last_sent_stream_id = 0, last_recv_stream_id = 19, last_proc_stream_id = 19,
next_unique_id = 0, local_last_stream_id = 2147483647, remote_last_stream_id =
2147483647,
remote_window_size = 15569316, recv_window_size = 0, consumed_size = 0,
recv_reduction = 0, local_window_size = 2147483647, remote_settings_received =
1 '\001',
remote_settings = {header_table_size = 65536, enable_push = 1,
max_concurrent_streams = 1000, initial_window_size = 6291456, max_frame_size =
16384,
max_header_list_size = 4294967295, enable_connect_protocol = 0,
no_rfc7540_priorities = 0}, local_settings = {header_table_size = 4096,
enable_push = 1,
max_concurrent_streams = 4294967295, initial_window_size = 65535,
max_frame_size = 16384, max_header_list_size = 4294967295,
enable_connect_protocol = 0,
no_rfc7540_priorities = 4294967295}, opt_flags = 81,
pending_local_max_concurrent_stream = 100, builtin_recv_ext_types = 0,
pending_enable_push = 1 '\001',
pending_enable_connect_protocol = 0 '\000', pending_no_rfc7540_priorities = 0
'\000', fallback_rfc7540_priorities = 0 '\000', server = 1 '\001', goaway_flags
= 0 '\000',
window_update_queued = 0 '\000', user_recv_ext_types = '\000' <repeats 31
times>}
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscr...@httpd.apache.org
For additional commands, e-mail: bugs-h...@httpd.apache.org
