Skip site navigation (1)Skip section navigation (2)
Date:      Fri, 18 Feb 2011 22:44:27 -0800
From:      'Jeremy Chadwick' <freebsd@jdc.parodius.com>
To:        Payam Poursaied <me@payam124.com>
Cc:        freebsd-apache@freebsd.org
Subject:   Re: apache 100% cpu usage
Message-ID:  <20110219064427.GA78063@icarus.home.lan>
In-Reply-To: <008701cbcfff$0a721590$1f5640b0$@com>
References:  <190201cbcfec$c76297f0$5627c7d0$@com> <20110219053032.GA76790@icarus.home.lan> <008701cbcfff$0a721590$1f5640b0$@com>

next in thread | previous in thread | raw e-mail | index | archive | help
On Sat, Feb 19, 2011 at 10:04:15AM +0330, Payam Poursaied wrote:
> > -----Original Message-----
> > From: Jeremy Chadwick [mailto:freebsd@jdc.parodius.com]
> > Sent: Saturday, February 19, 2011 9:01 AM
> > To: Payam Poursaied
> > Cc: freebsd-apache@freebsd.org
> > Subject: Re: apache 100% cpu usage
> > 
> > On Sat, Feb 19, 2011 at 07:53:31AM +0330, Payam Poursaied wrote:
> > > Hi all
> > > I faced with a problem using apache 1.3.42 on FreeBSD 8.0-RELEASE.
> > > The problem is that httpd processes frequently reach 100% CPU usage and stay
> > > at this level of CPU usage.
> > > This is a sample of top output.
> > >
> > >   PID USERNAME   THR PRI NICE   SIZE    RES STATE   C   TIME   WCPU COMMAND
> > > 77051 www          1 118    0   208M 86080K CPU4    4  87.6H 100.00% httpd
> > >  9403 www          1 118    0   215M 93340K CPU2    2  65.0H 100.00% httpd
> > > 78430 www          1 118    0   226M   100M CPU0    0  58:57 100.00% httpd
> > > 95332 www          1  50    0   205M 83624K sbwait 12   0:02  4.49% httpd
> > > 89664 www          1  46    0   210M 88144K sbwait 11   0:05  2.59% httpd
> > >
> > > I think there might be a bug that caused something like endless loop but I
> > > am newbie to gdb and debugging and I could not find any relevant point to
> > > get into it.
> > > I tried to compile apache in debug mode and then wait to see a suspicious
> > > process and then attached GDB66 to that cpu intensive httpd process to find
> > > out what is going on. It seems the problem is related to something in
> > > /lib/libc.so.7 which I could not find out how to compile it in debug mode.
> > >
> > > The result of "list" and "where" command of GDB are as below, I appreciate
> > > if you could point me to right direction to examine this problem deeply.
> > > As an extra information, mod_perl is heavily used trough this apache
> > >
> > > (gdb) l
> > > 5640
> > > 5641    #ifdef TPF
> > > 5642        EBW_AREA input_parms;
> > > 5643        ecbptr()->ebrout = PRIMECRAS;
> > > 5644        input_parms = * (EBW_AREA *)(&(ecbptr()->ebw000));
> > > 5645    #endif
> > > 5646
> > > 5647        MONCONTROL(0);
> > > 5648
> > > 5649        common_init();
> > > (gdb) w
> > > Ambiguous command "w": watch, wh, whatis, where, while, while-stepping,
> > > winheight, ws.
> > > (gdb) where
> > > #0  0x000000080093a9f5 in ?? () from /lib/libc.so.7
> > > #1  0x000000080093d505 in ?? () from /lib/libc.so.7
> > > #2  0x000000080093d702 in ?? () from /lib/libc.so.7
> > > #3  0x000000080094352e in ?? () from /lib/libc.so.7
> > > #4  0x0000000800944924 in realloc () from /lib/libc.so.7
> > > #5  0x000000080307a50f in Perl_safesysrealloc () from
> > > /usr/local/lib/perl5/5.10.1/mach/CORE/libperl.so
> > > #6  0x00000008030a6156 in Perl_sv_grow () from
> > > /usr/local/lib/perl5/5.10.1/mach/CORE/libperl.so
> > > #7  0x000000080309e32e in Perl_sv_vcatpvfn () from
> > > /usr/local/lib/perl5/5.10.1/mach/CORE/libperl.so
> > > #8  0x00000008030a7b42 in Perl_vnewSVpvf () from
> > > /usr/local/lib/perl5/5.10.1/mach/CORE/libperl.so
> > > #9  0x00000008030a7bf8 in Perl_newSVpvf () from
> > > /usr/local/lib/perl5/5.10.1/mach/CORE/libperl.so
> > > #10 0x000000080303da32 in Perl_gv_fetchmethod_autoload () from
> > > /usr/local/lib/perl5/5.10.1/mach/CORE/libperl.so
> > > #11 0x000000080308edca in S_method_common () from
> > > /usr/local/lib/perl5/5.10.1/mach/CORE/libperl.so
> > > #12 0x000000080308f462 in Perl_pp_method () from
> > > /usr/local/lib/perl5/5.10.1/mach/CORE/libperl.so
> > > #13 0x000000080308eb9e in Perl_runops_standard () from
> > > /usr/local/lib/perl5/5.10.1/mach/CORE/libperl.so
> > > #14 0x0000000803036191 in Perl_call_sv () from
> > > /usr/local/lib/perl5/5.10.1/mach/CORE/libperl.so
> > > #15 0x0000000802eabe36 in perl_call_handler () from
> > > /usr/local/libexec/apache/libperl.so
> > > #16 0x0000000802eac87a in perl_run_stacked_handlers () from
> > > /usr/local/libexec/apache/libperl.so
> > > #17 0x0000000802eae2b0 in perl_handler () from
> > > /usr/local/libexec/apache/libperl.so
> > > #18 0x000000000040ee42 in ap_invoke_handler (r=0x804624060) at
> > > http_config.c:476
> > > #19 0x0000000000427849 in process_request_internal (r=0x804624060) at
> > > http_request.c:1299
> > > #20 0x00000000004278a4 in ap_process_request (r=0x804624060) at
> > > http_request.c:1315
> > > #21 0x000000000041d423 in child_main (child_num_arg=14) at http_main.c:4885
> > > #22 0x000000000041d734 in make_child (s=0x800c05060, slot=14,
> > > now=1297853738) at http_main.c:5055
> > > #23 0x000000000041db6b in perform_idle_server_maintenance () at
> > > http_main.c:5256
> > > #24 0x000000000041e159 in standalone_main (argc=1, argv=0x7fffffffebd8) at
> > > http_main.c:5520
> > > #25 0x000000000041e7a4 in main (argc=1, argv=0x7fffffffebd8) at
> > > http_main.c:5773
> > 
> > This looks like you have a mod_perl problem, or a script that's doing
> > it.  It's probably not an Apache issue.
> > 
> > ktrace would be of more help here than gdb.  It will at least show you
> > what the children are doing in real-time, syscall-wise.  Correlating
> > this with underlying perl code is up to you/your problem, sadly.
> > 
> > Good luck.
> > 
> 
> Thank you for your fast response. I used truss and ktrace, but there wasn't any output to show any system calls or ..
> may I know how I can get inside and explore the problem? How it is possible to build  /lib/libc.so.7 in debug mode? Or
> any general how-to/instruction on debugging is appreciated.

truss on BSD is basically worthless, and buggy.  Don't bother.

ktrace won't show you any output -- it will simply start logging to a
binary file called ktrace.out (the manpage for ktrace(1) would have told
you this :-) ).  When you're finished tracing, "ktrace -C" or "ktrace -c
{pid}" should be used.  Once you've done that, "kdump" will read the
ktrace.out file and show you what was captured.

It helps if you know what to look for when using ktrace, but if you
don't know, the choice should be "ktrace -t+ -p {pid}", and "kdump -T"
or "kdump -R" (see kdump(1) for what the flags do).

The stack trace you provided does not indicate there is a problem in
libc.so.7, just that the stack is partially corrupted (and that can be
normal for a *lot* of reasons).  If anything, I would say the perl
instance run under mod_perl may be continually calling realloc().

I would highly recommend getting in touch with the mod_perl users
mailing list about your problem and start describing it.  They should be
able to provide help with debugging mod_perl scripts -- I have no idea
how to do such (I tend to avoid mod_perl due to all the gotchas of it;
it is not as simple as "turn it on and your perl scripts work faster").

If your mod_perl scripts can be made into standard perl (e.g. CGI)
scripts, I would recommend doing that then seeing if you can reproduce
the 100% CPU usage issue.  If you can, then you should be able to
reproduce it from the command line (rather than under Apache itself) as
well, and thus use the native perl debugger to figure things out.

But regardless, I doubt this is a problem with Apache or a problem with
FreeBSD.

-- 
| Jeremy Chadwick                                   jdc@parodius.com |
| Parodius Networking                       http://www.parodius.com/ |
| UNIX Systems Administrator                  Mountain View, CA, USA |
| Making life hard for others since 1977.               PGP 4BD6C0CB |




Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20110219064427.GA78063>