https://bz.apache.org/bugzilla/show_bug.cgi?id=57800
Bug ID: 57800
Summary: High CPU usage in ap_core_output_filter
Product: Apache httpd-2
Version: 2.4.10
Hardware: PC
OS: Linux
Status: NEW
Severity: normal
Priority: P2
Component: Core
Assignee: [email protected]
Reporter: [email protected]
Recently I got high CPU usage with never-stopping Apache threads.
Here is an htop line:
PID USER PRI NI VIRT RES SHR S CPU% MEM% TIME+ Command
8354 wwwrun 20 0 918M 185M 121M R 66.7 4.7 1h19:19
44060 wwwrun 20 0 988M 198M 138M R 66.7 5.0 1h57:14
45572 wwwrun 20 0 919M 79572 12844 R 33.3 2.0 41h29:29
Command is:
/usr/sbin/httpd2-prefork -f /etc/apache2/httpd.conf -DAWSTATS -DSSL -DICINGA -D
SYSTEMD -DFOREGROUND -k start
GDB backtrace of the last process gives me:
#0 ap_core_output_filter (f=0x7fc7bf4f1690, new_bb=0x7fc7bf4f1928) at
core_filters.c:512
#1 0x00007fc7ca37cf7d in ap_process_request_after_handler (r=0x7fc7bf4d50a0)
at http_request.c:256
#2 0x00007fc7ca37dbf4 in ap_process_request (r=r@entry=0x7fc7bf4d50a0) at
http_request.c:363
#3 0x00007fc7ca37a6a2 in ap_process_http_sync_connection (c=0x7fc7bf4f1290) at
http_core.c:190
#4 ap_process_http_connection (c=0x7fc7bf4f1290) at http_core.c:231
#5 0x00007fc7ca371fa0 in ap_run_process_connection (c=0x7fc7bf4f1290) at
connection.c:41
#6 0x00007fc7ca372388 in ap_process_connection (c=c@entry=0x7fc7bf4f1290,
csd=<optimized out>) at connection.c:203
#7 0x00007fc7ca38572e in child_main (child_num_arg=child_num_arg@entry=7) at
prefork.c:704
#8 0x00007fc7ca385962 in make_child (s=0x7fc7ca2db448, slot=7) at
prefork.c:800
#9 0x00007fc7ca3865ae in perform_idle_server_maintenance (p=<optimized out>)
at prefork.c:902
#10 prefork_run (_pconf=<optimized out>, plog=<optimized out>, s=<optimized
out>) at prefork.c:1090
#11 0x00007fc7ca34edde in ap_run_mpm (pconf=0x7fc7ca312028,
plog=0x7fc7ca2d7028, s=0x7fc7ca2db448) at mpm_common.c:94
#12 0x00007fc7ca348476 in main (argc=11, argv=0x7fffc04e2b58) at main.c:777
Full backtrace:
#0 ap_core_output_filter (f=0x7fc7bf4f1690, new_bb=0x7fc7bf4f1928) at
core_filters.c:512
c = 0x7fc7bf4f1290
net = 0x7fc7bf4f1648
ctx = 0x7fc7bf4f1748
bb = 0x7fc7bf4f1928
bucket = <optimized out>
next = 0x7fc7bf4e9048
flush_upto = 0x7fc7bf4e9048
bytes_in_brigade = 0
non_file_bytes_in_brigade = 0
eor_buckets_in_brigade = 4
morphing_bucket_in_brigade = 0
rv = <optimized out>
#1 0x00007fc7ca37cf7d in ap_process_request_after_handler (r=0x7fc7bf4d50a0)
at http_request.c:256
bb = 0x7fc7bf4f1928
b = <optimized out>
c = 0x7fc7bf4f1290
#2 0x00007fc7ca37dbf4 in ap_process_request (r=r@entry=0x7fc7bf4d50a0) at
http_request.c:363
bb = <optimized out>
b = <optimized out>
c = 0x7fc7bf4f1290
rv = <optimized out>
#3 0x00007fc7ca37a6a2 in ap_process_http_sync_connection (c=0x7fc7bf4f1290) at
http_core.c:190
r = 0x7fc7bf4d50a0
cs = 0x0
csd = 0x7fc7bf4f10a0
mpm_state = 1
#4 ap_process_http_connection (c=0x7fc7bf4f1290) at http_core.c:231
No locals.
#5 0x00007fc7ca371fa0 in ap_run_process_connection (c=0x7fc7bf4f1290) at
connection.c:41
pHook = 0x7fc7ca286720
n = 1
rv = -900044032
#6 0x00007fc7ca372388 in ap_process_connection (c=c@entry=0x7fc7bf4f1290,
csd=<optimized out>) at connection.c:203
rc = <optimized out>
#7 0x00007fc7ca38572e in child_main (child_num_arg=child_num_arg@entry=7) at
prefork.c:704
current_conn = 0x7fc7bf4f1290
csd = 0x7fc7bf4f10a0
thd = 0x7fc7bf4f30a0
osthd = 140496067344256
ptrans = 0x7fc7bf4f1028
allocator = 0x7fc7cb242570
status = <optimized out>
i = <optimized out>
lr = <optimized out>
pollset = 0x7fc7bf4f3180
sbh = 0x7fc7bf4f3178
bucket_alloc = 0x7fc7bf4ed028
last_poll_idx = 1
lockfile = <optimized out>
#8 0x00007fc7ca385962 in make_child (s=0x7fc7ca2db448, slot=7) at
prefork.c:800
pid = 0
#9 0x00007fc7ca3865ae in perform_idle_server_maintenance (p=<optimized out>)
at prefork.c:902
i = <optimized out>
idle_count = <optimized out>
ws = <optimized out>
free_length = <optimized out>
free_slots = {7, 8, 16, 17, 21, 22, 23, 24, 33, 34, 35, 36, 37, 38, 39,
40, 0 <repeats 16 times>}
last_non_dead = <optimized out>
total_non_dead = <optimized out>
#10 prefork_run (_pconf=<optimized out>, plog=<optimized out>, s=<optimized
out>) at prefork.c:1090
status = 11
pid = {pid = -1, in = 0x7fc7c9a525a0 <apr_pool_cleanup_null>, out =
0x0, err = 0x7fc7ca312028}
child_slot = <optimized out>
exitwhy = APR_PROC_SIGNAL
processed_status = <optimized out>
index = <optimized out>
remaining_children_to_start = 0
rv = <optimized out>
#11 0x00007fc7ca34edde in ap_run_mpm (pconf=0x7fc7ca312028,
plog=0x7fc7ca2d7028, s=0x7fc7ca2db448) at mpm_common.c:94
pHook = 0x7fc7ca286848
n = 0
rv = -900044032
#12 0x00007fc7ca348476 in main (argc=11, argv=0x7fffc04e2b58) at main.c:777
c = 68 'D'
showcompile = 0
showdirectives = 0
confname = 0x7fffc04e2eae "/etc/apache2/httpd.conf"
def_server_root = 0x7fc7ca3877e3 "/srv/www"
temp_error_log = 0x0
error = <optimized out>
process = 0x7fc7ca314118
pconf = 0x7fc7ca312028
plog = 0x7fc7ca2d7028
ptemp = 0x7fc7ca2d9028
pcommands = 0x7fc7ca2e1028
opt = 0x7fc7ca2e1118
rv = <optimized out>
mod = 0x7fc7ca5a8b18 <ap_prelinked_modules+56>
opt_arg = 0x7fffc04e2eec "FOREGROUND"
signal_server = <optimized out>
After letting it run for 3 seconds I get the following:
#0 ap_core_output_filter (f=0x7fc7bf4f1690, new_bb=0x7fc7bf4f1928) at
core_filters.c:509
#1 0x00007fc7ca37cf7d in ap_process_request_after_handler (r=0x7fc7bf4d50a0)
at http_request.c:256
#2 0x00007fc7ca37dbf4 in ap_process_request (r=r@entry=0x7fc7bf4d50a0) at
http_request.c:363
#3 0x00007fc7ca37a6a2 in ap_process_http_sync_connection (c=0x7fc7bf4f1290) at
http_core.c:190
#4 ap_process_http_connection (c=0x7fc7bf4f1290) at http_core.c:231
#5 0x00007fc7ca371fa0 in ap_run_process_connection (c=0x7fc7bf4f1290) at
connection.c:41
#6 0x00007fc7ca372388 in ap_process_connection (c=c@entry=0x7fc7bf4f1290,
csd=<optimized out>) at connection.c:203
#7 0x00007fc7ca38572e in child_main (child_num_arg=child_num_arg@entry=7) at
prefork.c:704
#8 0x00007fc7ca385962 in make_child (s=0x7fc7ca2db448, slot=7) at
prefork.c:800
#9 0x00007fc7ca3865ae in perform_idle_server_maintenance (p=<optimized out>)
at prefork.c:902
#10 prefork_run (_pconf=<optimized out>, plog=<optimized out>, s=<optimized
out>) at prefork.c:1090
#11 0x00007fc7ca34edde in ap_run_mpm (pconf=0x7fc7ca312028,
plog=0x7fc7ca2d7028, s=0x7fc7ca2db448) at mpm_common.c:94
#12 0x00007fc7ca348476 in main (argc=11, argv=0x7fffc04e2b58) at main.c:777
And the top function of the backtrace:
#0 ap_core_output_filter (f=0x7fc7bf4f1690, new_bb=0x7fc7bf4f1928) at
core_filters.c:509
c = 0x7fc7bf4f1290
net = 0x7fc7bf4f1648
ctx = 0x7fc7bf4f1748
bb = 0x7fc7bf4f1928
bucket = <optimized out>
next = 0x7fc7bf4e9048
flush_upto = 0x7fc7bf4e9048
bytes_in_brigade = 0
non_file_bytes_in_brigade = 0
eor_buckets_in_brigade = 0
morphing_bucket_in_brigade = 0
rv = <optimized out>
An other thread shows the same with a bit different top function call line:
#0 0x00007fc7ca3640fa in ap_core_output_filter (f=0x7fc7bf4f1690,
new_bb=0x7fc7bf4f1928) at core_filters.c:493
c = 0x7fc7bf4f1290
net = 0x7fc7bf4f1648
ctx = 0x7fc7bf4f1748
bb = 0x7fc7bf4f1928
bucket = <optimized out>
next = 0x7fc7bf4e9048
flush_upto = 0x7fc7bf4e9048
bytes_in_brigade = 0
non_file_bytes_in_brigade = 0
eor_buckets_in_brigade = 1
morphing_bucket_in_brigade = 0
rv = <optimized out>
There is no significant workload according to netstat -t:
Active Internet connections (w/o servers)
Proto Recv-Q Send-Q Local Address Foreign Address State
tcp 0 0 server-name:www-http al121.albit.fastw:33532 TIME_WAIT
tcp 1 0 server-name:www-http 5E1BB7D7.mobile.p:51177 CLOSE_WAIT
tcp 0 0 server-name:www-http b110196.yse.yahoo:34908 TIME_WAIT
After I restart the server, the workload is OK for some hours and it starts
again.
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
