On Wednesday, November 12, 2014 2:25:47 AM UTC+11, Tim.Bunce wrote:
>
> On Mon, Nov 10, 2014 at 06:16:59PM -0800, [email protected] 
> <javascript:> wrote: 
> > 
> >    So today I've been trying to delay the loading of 
> Devel::NYTProf::Apache until it's in a child 
> >    interpreter. 
>
> Load it in the parent but ensure the NYTPROF 'start' option is set to 
> 'no'. 
> https://metacpan.org/pod/Devel::NYTProf#start 
> https://metacpan.org/pod/Devel::NYTProf#RUN-TIME-CONTROL-OF-PROFILING 
>

Right! That's exactly what I've been doing. But NYTProf still calls 
init_profiler immediately, then ignores calls to enable_profile.

Here is an example. In http.conf, I have "PerlSetEnv NYTPROF 
start=no:trace=1":

$ sudo service apache2 start
$ cat /var/log/apache2/error.log
# trace=1
# endatexit=1
# addpid=1
~ init_profiler for pid 10870, clock 1, tps 10000000, start 0, perldb 
0xf10, exitf 0x2
~ init_profiler done
~ END done
~ finish_profile (overhead 0t, is_profiling 0)
~ disable_profile (previously disabled, pid 10870, trace 1)
~ END done
~ finish_profile (overhead 0t, is_profiling 0)
~ disable_profile (previously disabled, pid 10870, trace 1)
~ finish_profile (overhead 0t, is_profiling 0)
~ disable_profile (previously disabled, pid 10870, trace 1)
# trace=1
# endatexit=1
# addpid=1
~ init_profiler for pid 10871, clock 1, tps 10000000, start 0, perldb 
0xf10, exitf 0x2
~ init_profiler done
[Wed Nov 12 10:05:00.631765 2014] [mpm_prefork:notice] [pid 10871] AH00163: 
Apache/2.4.7 (Ubuntu) mod_perl/2.0.8 Perl/v5.18.2 configured -- resuming 
normal operations
[Wed Nov 12 10:05:00.631809 2014] [core:notice] [pid 10871] AH00094: 
Command line: '/usr/sbin/apache2'

So far this is the same whether I'm running Apache MPM prefork or worker. 
But the behavior diverges once Apache accepts its first request and the web 
app calls DB::enable_profile():

In MPM prefork, everything is awesome:

~ enable_profile (previously disabled) to 
/tmp/nytprof.ns.1415747125.488050.out
~ new pid 10875 (was 10871) forkdepth -1
~ opened /tmp/nytprof.ns.1415747125.488050.out.10875 at 1415747125.533632
~ first statement profiled at line 110 of /var/www/cgi-bin/index.cgi, pid 
10875
~ finish_profile (overhead 26825t, is_profiling 1)
~ disable_profile (previously enabled, pid 10875, trace 1)
~ writing file source code
~ writing sub line ranges - prescan
~ writing sub line ranges of 3202 subs
~ writing sub callers for 229 subs
~ closed file at 1415747126.277812

In MPM worker, not so good:

~ enable_profile call from different interpreter ignored
~ finish_profile call from different interpreter ignored

There are definitely no calls to enable_profile before this. In fact, under 
this setup, enable_profile never gets called, not once, by anything.

By the way, I don't know if this is related, but I discovered some strange 
behavior with setting NYTPROF, after I got suspicious about how there's no 
"# start=no" line in the log despite that option definitely being set. What 
I found is that if NYTPROF is set to "file=<whatever>" only, then Apache 
MPM worker segfaults. But if I throw in an additional valid option, it 
doesn't. E.g.:

NYTPROF=file=/tmp  -->segfault
NYTPROF=file=/tmp:start=no  --> works fine
NYTPROF=trace=1:file=/tmp   --> works fine
NYTPROF=file=/tmp:foo=bar  --> segfault

It also segfaults if NYTPROF isn't defined, due to the default:

NYTPROF env var not set, so defaulting to 
NYTPROF='file=/tmp/nytprof.12033.out' at 
/usr/lib/perl5/Devel/NYTProf/Apache.pm line 22.

You may not care, since this only happens under MPM worker and NYTProf 
isn't supposed to be thread-safe, but I thought it was odd enough to 
mention.

I didn't discover why the log doesn't say "# start=no". But NYTProf's 
behavior is a little different with that option set--it makes no 
enable_profile calls--so it does seem to be registered.
 

> Moritz's suggestion sounds more directly useful. 
>

Mmm, yes, thank you for that, Moritz! But I am loathe to go down that path 
since we've tried running multiple instances of Apache in the past and had 
issues. It's definitely doable, it's just a more difficult setup to 
maintain going forward.

Max.

-- 
-- 
You've received this message because you are subscribed to
the Devel::NYTProf Development User group.

Group hosted at:  http://groups.google.com/group/develnytprof-dev
Project hosted at:  http://perl-devel-nytprof.googlecode.com
CPAN distribution:  http://search.cpan.org/dist/Devel-NYTProf

To post, email:  [email protected]
To unsubscribe, email:  [email protected]
--- 
You received this message because you are subscribed to the Google Groups 
"Devel::NYTProf Dev" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to [email protected].
For more options, visit https://groups.google.com/d/optout.

Reply via email to