Under load an httpd client process will start using 100% of the cpu when mod_example is loaded. Mod_example is built when --enable-modules=all is specified and is loaded in the default httpd.conf so some users may be loading this module inadvertently. ./httpd -V Server version: Apache/2.2.17-b2 (Unix) Server built: Jan 14 2011 15:59:39 Server's Module Magic Number: 20051115:25 Server loaded: APR 1.4.2, APR-Util 1.3.10 Compiled using: APR 1.4.2, APR-Util 1.3.10 Architecture: 64-bit Server MPM: Worker threaded: yes (fixed thread count) forked: yes (variable process count) Server compiled with.... -D APACHE_MPM_DIR="server/mpm/worker" -D APR_HAS_SENDFILE -D APR_HAS_MMAP -D APR_HAVE_IPV6 (IPv4-mapped addresses enabled) -D APR_USE_SYSVSEM_SERIALIZE -D APR_USE_PTHREAD_SERIALIZE -D SINGLE_LISTEN_UNSERIALIZED_ACCEPT -D APR_HAS_OTHER_CHILD -D AP_HAVE_RELIABLE_PIPED_LOGS -D DYNAMIC_MODULE_LIMIT=128 -D HTTPD_ROOT="/opt/lamp/2.2.17-b2/httpd-2.2.17" -D SUEXEC_BIN="/opt/lamp/2.2.17-b2/httpd-2.2.17/bin/suexec" -D DEFAULT_SCOREBOARD="logs/apache_runtime_status" -D DEFAULT_ERRORLOG="logs/error_log" -D AP_TYPES_CONFIG_FILE="conf/mime.types" -D SERVER_CONFIG_FILE="conf/httpd.conf" top - 12:19:21 up 94 days, 17:40, 2 users, load average: 3.06, 3.00, 2.44 Tasks: 132 total, 2 running, 130 sleeping, 0 stopped, 0 zombie Cpu(s): 75.0%us, 0.0%sy, 0.0%ni, 24.7%id, 0.2%wa, 0.0%hi, 0.0%si, 0.0%st Mem: 16438704k total, 3579040k used, 12859664k free, 232204k buffers Swap: 0k total, 0k used, 0k free, 2950136k cached PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 14624 daemon 18 0 688m 23m 2036 S 100.2 0.1 26:50.49 httpd 12422 daemon 18 0 814m 24m 2012 S 99.9 0.1 22:07.22 httpd 12424 daemon 23 0 624m 23m 2028 S 99.9 0.1 32:22.28 httpd 21459 root 15 0 10648 1036 756 R 0.3 0.0 0:00.01 top 1 root 15 0 10348 660 560 S 0.0 0.0 0:03.29 init 2 root RT -5 0 0 0 S 0.0 0.0 0:01.90 migration/0 (gdb) info threads 27 Thread 0x42756940 (LWP 12438) 0x0000003f07e0d4c4 in __lll_lock_wait () from /lib64/libpthread.so.0 26 Thread 0x43157940 (LWP 12440) 0x0000003f07e0d4c4 in __lll_lock_wait () from /lib64/libpthread.so.0 25 Thread 0x43b58940 (LWP 12452) 0x0000003f07e0aee9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0 24 Thread 0x44559940 (LWP 12454) 0x0000003f07e0d4c4 in __lll_lock_wait () from /lib64/libpthread.so.0 23 Thread 0x44f5a940 (LWP 12456) 0x0000003f07e0d4c4 in __lll_lock_wait () from /lib64/libpthread.so.0 22 Thread 0x4595b940 (LWP 12458) 0x0000003f07e0d4c4 in __lll_lock_wait () from /lib64/libpthread.so.0 21 Thread 0x4635c940 (LWP 12459) 0x0000003f07e0d4c4 in __lll_lock_wait () from /lib64/libpthread.so.0 20 Thread 0x46d5d940 (LWP 12460) 0x0000003f07e0d4c4 in __lll_lock_wait () from /lib64/libpthread.so.0 19 Thread 0x4775e940 (LWP 12461) 0x0000003f07e0d4c4 in __lll_lock_wait () from /lib64/libpthread.so.0 18 Thread 0x4815f940 (LWP 12469) 0x0000003f07e0d4c4 in __lll_lock_wait () from /lib64/libpthread.so.0 17 Thread 0x48b60940 (LWP 12470) 0x0000003f07e0d4c4 in __lll_lock_wait () from /lib64/libpthread.so.0 16 Thread 0x49561940 (LWP 12471) 0x0000003f07e0d4c4 in __lll_lock_wait () from /lib64/libpthread.so.0 15 Thread 0x49f62940 (LWP 12472) 0x0000003f07e0d4c4 in __lll_lock_wait () from /lib64/libpthread.so.0 14 Thread 0x4a963940 (LWP 12473) 0x00002aab88695b4c in apr_pool_destroy (pool=0x154013a8) at memory/unix/apr_pools.c:369 13 Thread 0x4b364940 (LWP 12474) 0x0000003f07e0d4c4 in __lll_lock_wait () from /lib64/libpthread.so.0 12 Thread 0x4bd65940 (LWP 12475) 0x0000003f07e0d4c4 in __lll_lock_wait () from /lib64/libpthread.so.0 11 Thread 0x4c766940 (LWP 12484) 0x0000003f07e0d4c4 in __lll_lock_wait () from /lib64/libpthread.so.0 10 Thread 0x4d167940 (LWP 12486) 0x0000003f07e0d4c4 in __lll_lock_wait () from /lib64/libpthread.so.0 9 Thread 0x4db68940 (LWP 12488) 0x0000003f07e0d4c4 in __lll_lock_wait () from /lib64/libpthread.so.0 8 Thread 0x4e569940 (LWP 12490) 0x0000003f07e0d4c4 in __lll_lock_wait () from /lib64/libpthread.so.0 7 Thread 0x4ef6a940 (LWP 12492) 0x0000003f07e0d4c4 in __lll_lock_wait () from /lib64/libpthread.so.0 6 Thread 0x4f96b940 (LWP 12494) 0x0000003f07e0d4c4 in __lll_lock_wait () from /lib64/libpthread.so.0 5 Thread 0x5036c940 (LWP 12496) 0x0000003f07e0aee9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0 4 Thread 0x50d6d940 (LWP 12499) 0x0000003f07e0d4c4 in __lll_lock_wait () from /lib64/libpthread.so.0 3 Thread 0x5176e940 (LWP 12501) 0x0000003f07e0d4c4 in __lll_lock_wait () from /lib64/libpthread.so.0 2 Thread 0x5216f940 (LWP 12503) 0x0000003f07e0d4c4 in __lll_lock_wait () from /lib64/libpthread.so.0 * 1 Thread 0x2aab888ac470 (LWP 12422) 0x0000003f07e0d91b in read () from /lib64/libpthread.so.0 gdb) thread 14 [Switching to thread 14 (Thread 0x4a963940 (LWP 12473))]#0 0x00002aab88695b4c in apr_pool_destroy (pool=0x154013a8) at memory/unix/apr_pools.c:369 369 if ((node->next = allocator->free[index]) == NULL (gdb) bt #0 0x00002aab88695b4c in apr_pool_destroy (pool=0x154013a8) at memory/unix/apr_pools.c:369 #1 0x00002aab8bb30363 in trace_add (s=<value optimized out>, r=0x0, mconfig=0x1535a7e0, note=0x2aab8bb31129 "x_quick_handler()") at mod_example.c:378 #2 0x00002aab8bb3059e in x_quick_handler (r=0x2aaab000e9d0, lookup_uri=<value optimized out>) at mod_example.c:982 #3 0x0000000000436cb3 in ap_run_quick_handler (r=0x2aaab000e9d0, lookup=0) at config.c:160 #4 0x0000000000444151 in ap_process_request (r=0x2aaab000e9d0) at http_request.c:278 #5 0x00000000004415ac in ap_process_http_connection (c=0x16b027f8) at http_core.c:190 #6 0x000000000043db32 in ap_run_process_connection (c=0x16b027f8) at connection.c:43 #7 0x0000000000448bc4 in worker_thread (thd=0x153fbd30, dummy=<value optimized out>) at worker.c:544 #8 0x0000003f07e0673d in start_thread () from /lib64/libpthread.so.0 #9 0x0000003f072d3f6d in clone () from /lib64/libc.so.6 (gdb) s 358 index = node->index; (gdb) s 357 next = node->next; (gdb) s 360 if (max_free_index != APR_ALLOCATOR_MAX_FREE_UNLIMITED (gdb) s 365 else if (index < MAX_INDEX) { (gdb) s 369 if ((node->next = allocator->free[index]) == NULL (gdb) s 374 if (current_free_index >= index) (gdb) s 373 allocator->free[index] = node; (gdb) s 374 if (current_free_index >= index) (gdb) s 386 current_free_index -= index; (gdb) s 390 } while ((node = next) != NULL); (gdb) s 358 index = node->index; (gdb) s 357 next = node->next; (gdb) s 360 if (max_free_index != APR_ALLOCATOR_MAX_FREE_UNLIMITED (gdb) s 365 else if (index < MAX_INDEX) { (gdb) s 369 if ((node->next = allocator->free[index]) == NULL (gdb) s 374 if (current_free_index >= index) (gdb) s 373 allocator->free[index] = node; (gdb) s 374 if (current_free_index >= index) (gdb) s 386 current_free_index -= index; (gdb) s 390 } while ((node = next) != NULL); (gdb) s 358 index = node->index;
quick handler mis-calls trace_add and triggers non-thread-safe code usually run during init this probably fixes it Index: modules/experimental/mod_example.c =================================================================== --- modules/experimental/mod_example.c (revision 1082598) +++ modules/experimental/mod_example.c (working copy) @@ -922,7 +922,7 @@ /* * Log the call and exit. */ - trace_add(r->server, NULL, cfg, "x_http_scheme()"); + trace_add(r->server, r, cfg, "x_http_scheme()"); return "example"; } @@ -941,7 +941,7 @@ /* * Log the call and exit. */ - trace_add(r->server, NULL, cfg, "x_default_port()"); + trace_add(r->server, r, cfg, "x_default_port()"); return 80; } #endif /*0*/ @@ -961,7 +961,7 @@ /* * Log the call and exit. */ - trace_add(r->server, NULL, cfg, "x_insert_filter()"); + trace_add(r->server, r, cfg, "x_insert_filter()"); } /* @@ -979,7 +979,7 @@ /* * Log the call and exit. */ - trace_add(r->server, NULL, cfg, "x_quick_handler()"); + trace_add(r->server, r, cfg, "x_quick_handler()"); return DECLINED; } (I presume the submitter doesn't particularly care about mod_example; no need to test the fix)
I applied the patch and retested and it does appear to be fixed. But you are correct, I'm not much interested in mod_example.
*** This bug has been marked as a duplicate of bug 32051 ***