Login | Register For Free | Help
Search for: (Advanced)

Mailing List Archive: ModPerl: Dev

Startup Slow with DSO mod_perl

  

 
ModPerl dev RSS feed   Index | Next | Previous | View Threaded


david at kineticode

Apr 3, 2009, 2:38 PM

Post #1 of 17 (5190 views)
Permalink
Startup Slow with DSO mod_perl
Hey Guys,

So I've been doing some testing of Bricolage with mod_perl 1.31rc7 and
with mod_perl 2.04 (and Perl 5.10 and Apache 1.3.41 and 2.2.11), and
I'm finding something very strange: Apache is *very* slow to start
when mod_perl is a DSO.

The bit that's slow, curiously, is this:

PerlModule Bric::App::ApacheConfig

What that module does is load all of the Bricolage Perl modules and
dependencies, generate some virtual host configuration, and then
either insert it into $Apache::ReadConfig::Include (under mod_perl 1)
or write it to a file and include it from httpd.conf using the Include
directive. Under statuc mod_perl 1, this all happens very fast;
Bricolage starts up in a couple of seconds at most. But under
mod_perl1 with a DSO or mod_perl2 (also a DSO), it's very slow: 25-30
seconds. If I comment-out the Bric::App::ApacheConfig call, it's fast
again (although Bricolage is not, of course, properly configured).

Now, the really odd thing is that Bric::App::ApacheConfig seems to run
just fine, and quickly, no matter what. If I put some `print STDERR`
statements at the end of it, they're output to the log very quickly.
If I put another PerlModule after the Bric::App::ApacheConfig one, and
just have *it* print to STDERR, that's also very quick. So something
is happening after it runs. Or so it seems.

So, anyone have any idea what might be happening here? I've been
battling this for hours and I'm completely stumped. FWIW, I'm on Mac
OS X 1.10.5 (Darwin Kernel Version 9.6.0).

Thanks for any insights. I'm going to see if I can break this on my
Ubuntu server, too.

Best,

David

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe[at]perl.apache.org
For additional commands, e-mail: dev-help[at]perl.apache.org


david at kineticode

Apr 3, 2009, 2:50 PM

Post #2 of 17 (5045 views)
Permalink
Re: Startup Slow with DSO mod_perl [In reply to]
On Apr 3, 2009, at 2:38 PM, David E. Wheeler wrote:

> Thanks for any insights. I'm going to see if I can break this on my
> Ubuntu server, too.

It seems to be slow there, too. It takes about 6 seconds to start up
(Apache/2.2.8 (Unix) mod_ssl/2.2.8 OpenSSL/0.9.8g
mod_apreq2-20051231/2.6.0 mod_perl/2.0.4 Perl/v5.10.0)

Thanks,

David

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe[at]perl.apache.org
For additional commands, e-mail: dev-help[at]perl.apache.org


gozer at ectoplasm

Apr 3, 2009, 6:11 PM

Post #3 of 17 (5043 views)
Permalink
Re: Startup Slow with DSO mod_perl [In reply to]
On 3/4/09 17:50, David E. Wheeler wrote:
> On Apr 3, 2009, at 2:38 PM, David E. Wheeler wrote:
>
>> Thanks for any insights. I'm going to see if I can break this on my
>> Ubuntu server, too.
>
> It seems to be slow there, too. It takes about 6 seconds to start up
> (Apache/2.2.8 (Unix) mod_ssl/2.2.8 OpenSSL/0.9.8g
> mod_apreq2-20051231/2.6.0 mod_perl/2.0.4 Perl/v5.10.0)

Any insights on what's it doing when it's acting up slow?

I'd look at running httpd under strace (or equivalent) just to get an idea
as to what it's doing that's so different than the static case.

--
Philippe M. Chiasson GPG: F9BFE0C2480E7680 1AE53631CB32A107 88C3A5A5
http://gozer.ectoplasm.org/ m/gozer\@(apache|cpan|ectoplasm)\.org/
Attachments: signature.asc (0.18 KB)


david at kineticode

Apr 3, 2009, 6:20 PM

Post #4 of 17 (5046 views)
Permalink
Re: Startup Slow with DSO mod_perl [In reply to]
On Apr 3, 2009, at 6:11 PM, Philippe M. Chiasson wrote:

>> It seems to be slow there, too. It takes about 6 seconds to start up
>> (Apache/2.2.8 (Unix) mod_ssl/2.2.8 OpenSSL/0.9.8g
>> mod_apreq2-20051231/2.6.0 mod_perl/2.0.4 Perl/v5.10.0)
>
> Any insights on what's it doing when it's acting up slow?
>
> I'd look at running httpd under strace (or equivalent) just to get
> an idea
> as to what it's doing that's so different than the static case.

No. It does seem like if I stop and start very quickly on my Mac, the
startup is pretty quick, just a few seconds. But if I wait 30-60s
after shutting down before starting up again, it's slow again. But
it's not always quicker on the quick restart.

Otherwise, the only other thing I've noticed is that it's never slow
with static mod_perl1.

Where do I find something to tell me how to use strace with Apache on
Mac OS X? Pointers appreciated.

Best,

David

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe[at]perl.apache.org
For additional commands, e-mail: dev-help[at]perl.apache.org


gozer at ectoplasm

Apr 3, 2009, 6:36 PM

Post #5 of 17 (5047 views)
Permalink
Re: Startup Slow with DSO mod_perl [In reply to]
On 3/4/09 21:20, David E. Wheeler wrote:
> On Apr 3, 2009, at 6:11 PM, Philippe M. Chiasson wrote:
>
>>> It seems to be slow there, too. It takes about 6 seconds to start up
>>> (Apache/2.2.8 (Unix) mod_ssl/2.2.8 OpenSSL/0.9.8g
>>> mod_apreq2-20051231/2.6.0 mod_perl/2.0.4 Perl/v5.10.0)
>>
>> Any insights on what's it doing when it's acting up slow?
>>
>> I'd look at running httpd under strace (or equivalent) just to get
>> an idea
>> as to what it's doing that's so different than the static case.
>
> No. It does seem like if I stop and start very quickly on my Mac, the
> startup is pretty quick, just a few seconds. But if I wait 30-60s
> after shutting down before starting up again, it's slow again. But
> it's not always quicker on the quick restart.
>
> Otherwise, the only other thing I've noticed is that it's never slow
> with static mod_perl1.
>
> Where do I find something to tell me how to use strace with Apache on
> Mac OS X? Pointers appreciated.

Assuming you are running 10.5, try dtruss

$> sudo dtruss /path/to/my/httpd -X [...]

Should spew out what it's up to.

But this could be very well just be cost you are paying for loading a bunch
of shared libraries, it's not something blazing fast on OS X. Just guessing.

--
Philippe M. Chiasson GPG: F9BFE0C2480E7680 1AE53631CB32A107 88C3A5A5
http://gozer.ectoplasm.org/ m/gozer\@(apache|cpan|ectoplasm)\.org/
Attachments: signature.asc (0.18 KB)


david at kineticode

Apr 6, 2009, 11:58 AM

Post #6 of 17 (5013 views)
Permalink
Re: Startup Slow with DSO mod_perl [In reply to]
On Apr 3, 2009, at 6:36 PM, Philippe M. Chiasson wrote:

>> Where do I find something to tell me how to use strace with Apache on
>> Mac OS X? Pointers appreciated.
>
> Assuming you are running 10.5, try dtruss
>
> $> sudo dtruss /path/to/my/httpd -X [...]
>
> Should spew out what it's up to.

Thanks. Output attached. I put this in a BEGIN block in the Bricolage
loading and configuration module:


BEGIN {
print STDERR '@' x 78;
print STDERR "Running Bric::App:ApacheConfig\n";
print STDERR '@' x 78;
}

And stuck this at the end of it:

print STDERR '@' x 78;
print STDERR "Done running Bric::App:ApacheConfig\n";
print STDERR '@' x 78;

> But this could be very well just be cost you are paying for loading
> a bunch
> of shared libraries, it's not something blazing fast on OS X. Just
> guessing.

It sure seems to be loading a shitload more Perl modules; they all
load with static mod_perl, too, though, and that's good and fast.
There are also a ton of calls to munmap(). Other than obvious
flushing, I don't see it getting hung up on any one thing. :-(

Thanks,

David
Attachments: startup.txt.gz (397 KB)


gozer at ectoplasm

Apr 6, 2009, 12:13 PM

Post #7 of 17 (5020 views)
Permalink
Re: Startup Slow with DSO mod_perl [In reply to]
On 6/4/09 14:58, David E. Wheeler wrote:
> On Apr 3, 2009, at 6:36 PM, Philippe M. Chiasson wrote:
>
>>> Where do I find something to tell me how to use strace with Apache on
>>> Mac OS X? Pointers appreciated.
>>
>> Assuming you are running 10.5, try dtruss
>>
>> $> sudo dtruss /path/to/my/httpd -X [...]
>>
> [...]
>
> It sure seems to be loading a shitload more Perl modules; they all
> load with static mod_perl, too, though, and that's good and fast.
> There are also a ton of calls to munmap(). Other than obvious
> flushing, I don't see it getting hung up on any one thing. :-(

It would be more interesting to compare the differences in dtruss output
between static and dynamic, looking for some glaring differences.

--
Philippe M. Chiasson GPG: F9BFE0C2480E7680 1AE53631CB32A107 88C3A5A5
http://gozer.ectoplasm.org/ m/gozer\@(apache|cpan|ectoplasm)\.org/
Attachments: signature.asc (0.18 KB)


david at kineticode

Apr 6, 2009, 12:59 PM

Post #8 of 17 (5015 views)
Permalink
Re: Startup Slow with DSO mod_perl [In reply to]
On Apr 6, 2009, at 12:13 PM, Philippe M. Chiasson wrote:

>> It sure seems to be loading a shitload more Perl modules; they all
>> load with static mod_perl, too, though, and that's good and fast.
>> There are also a ton of calls to munmap(). Other than obvious
>> flushing, I don't see it getting hung up on any one thing. :-(
>
> It would be more interesting to compare the differences in dtruss
> output
> between static and dynamic, looking for some glaring differences.

Right, sensible. I've attached output for statically-compiled and DSO
mod_perl1 (I've never built a static mod_perl 2). The DSO file is
twice the size, so something is quite different.

Thanks,

David
Attachments: static.txt.gz (201 KB)
  dso.txt.gz (393 KB)


gozer at ectoplasm

Apr 7, 2009, 7:10 PM

Post #9 of 17 (4979 views)
Permalink
Re: Startup Slow with DSO mod_perl [In reply to]
On 6/4/09 15:59, David E. Wheeler wrote:
> On Apr 6, 2009, at 12:13 PM, Philippe M. Chiasson wrote:
>
>>> It sure seems to be loading a shitload more Perl modules; they all
>>> load with static mod_perl, too, though, and that's good and fast.
>>> There are also a ton of calls to munmap(). Other than obvious
>>> flushing, I don't see it getting hung up on any one thing. :-(
>>
>> It would be more interesting to compare the differences in dtruss
>> output
>> between static and dynamic, looking for some glaring differences.
>
> Right, sensible. I've attached output for statically-compiled and DSO
> mod_perl1 (I've never built a static mod_perl 2). The DSO file is
> twice the size, so something is quite different.

Looks like in the DSO case, you end up with what looks like double the
work, and very similar, kinda like a start/restart cycle.

I don't remember apache 1.3, but would it be possible that it does a restart
on start _only_ for the DSO case ?

--
Philippe M. Chiasson GPG: F9BFE0C2480E7680 1AE53631CB32A107 88C3A5A5
http://gozer.ectoplasm.org/ m/gozer\@(apache|cpan|ectoplasm)\.org/
Attachments: signature.asc (0.18 KB)


david at kineticode

Apr 7, 2009, 8:07 PM

Post #10 of 17 (4983 views)
Permalink
Re: Startup Slow with DSO mod_perl [In reply to]
On Apr 7, 2009, at 7:10 PM, Philippe M. Chiasson wrote:

> Looks like in the DSO case, you end up with what looks like double the
> work, and very similar, kinda like a start/restart cycle.

I've noticed that at times; the same code loading/running twice.

> I don't remember apache 1.3, but would it be possible that it does a
> restart
> on start _only_ for the DSO case ?

What's a "restart on start"?

Best,

David


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe[at]perl.apache.org
For additional commands, e-mail: dev-help[at]perl.apache.org


adam.prime at utoronto

Apr 7, 2009, 8:15 PM

Post #11 of 17 (4985 views)
Permalink
Re: Startup Slow with DSO mod_perl [In reply to]
David E. Wheeler wrote:
> On Apr 7, 2009, at 7:10 PM, Philippe M. Chiasson wrote:
>
>> Looks like in the DSO case, you end up with what looks like double the
>> work, and very similar, kinda like a start/restart cycle.
>
> I've noticed that at times; the same code loading/running twice.
>
>> I don't remember apache 1.3, but would it be possible that it does a
>> restart
>> on start _only_ for the DSO case ?
>
> What's a "restart on start"?
>

According to the guide, it did it in apache 1.3 too.

http://perl.apache.org/docs/1.0/guide/config.html#Apache_Restarts_Twice_On_Start

Adam

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe[at]perl.apache.org
For additional commands, e-mail: dev-help[at]perl.apache.org


david at kineticode

Apr 7, 2009, 10:05 PM

Post #12 of 17 (4986 views)
Permalink
Re: Startup Slow with DSO mod_perl [In reply to]
On Apr 7, 2009, at 8:15 PM, Adam Prime wrote:

>> What's a "restart on start"?
>
> According to the guide, it did it in apache 1.3 too.
>
> http://perl.apache.org/docs/1.0/guide/config.html#Apache_Restarts_Twice_On_Start

Oh, right, I remember that. But it says that the modules loaded via
PerlModule (as Bricolage is loaded) do *not* get compiled twice.

Best,

David


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe[at]perl.apache.org
For additional commands, e-mail: dev-help[at]perl.apache.org


gozer at ectoplasm

Apr 7, 2009, 10:49 PM

Post #13 of 17 (4978 views)
Permalink
Re: Startup Slow with DSO mod_perl [In reply to]
On 8/4/09 01:05, David E. Wheeler wrote:
> On Apr 7, 2009, at 8:15 PM, Adam Prime wrote:
>
>>> What's a "restart on start"?
>>
>> According to the guide, it did it in apache 1.3 too.
>>
>> http://perl.apache.org/docs/1.0/guide/config.html#Apache_Restarts_Twice_On_Start
>
> Oh, right, I remember that. But it says that the modules loaded via
> PerlModule (as Bricolage is loaded) do *not* get compiled twice.

Except in the case of DSOs, where the whole .so gets unloaded/loaded, so
libperl/Perl goes away with it.

This is a flaw in the documentation, I suspect. Keep in mind that most
mod_perl 1.x users use static compilation, so the DSO case is not very
common.

--
Philippe M. Chiasson GPG: F9BFE0C2480E7680 1AE53631CB32A107 88C3A5A5
http://gozer.ectoplasm.org/ m/gozer\@(apache|cpan|ectoplasm)\.org/
Attachments: signature.asc (0.18 KB)


david at kineticode

Apr 8, 2009, 9:47 AM

Post #14 of 17 (4973 views)
Permalink
Re: Startup Slow with DSO mod_perl [In reply to]
On Apr 7, 2009, at 10:49 PM, Philippe M. Chiasson wrote:

>>> http://perl.apache.org/docs/1.0/guide/config.html#Apache_Restarts_Twice_On_Start
>>
>> Oh, right, I remember that. But it says that the modules loaded via
>> PerlModule (as Bricolage is loaded) do *not* get compiled twice.
>
> Except in the case of DSOs, where the whole .so gets unloaded/
> loaded, so
> libperl/Perl goes away with it.
>
> This is a flaw in the documentation, I suspect. Keep in mind that most
> mod_perl 1.x users use static compilation, so the DSO case is not very
> common.

Yeah, but not so in mod_perl2. And 30 seconds is an awfully long time
to wait for a startup…is there nothing I can do to reduce the start
time?

Best,

David
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe[at]perl.apache.org
For additional commands, e-mail: dev-help[at]perl.apache.org


gozer at ectoplasm

Apr 10, 2009, 11:38 AM

Post #15 of 17 (4922 views)
Permalink
Re: Startup Slow with DSO mod_perl [In reply to]
On 8/4/09 12:47, David E. Wheeler wrote:
> On Apr 7, 2009, at 10:49 PM, Philippe M. Chiasson wrote:
>
>>>> http://perl.apache.org/docs/1.0/guide/config.html#Apache_Restarts_Twice_On_Start
>>>
>>> Oh, right, I remember that. But it says that the modules loaded via
>>> PerlModule (as Bricolage is loaded) do *not* get compiled twice.
>>
>> Except in the case of DSOs, where the whole .so gets unloaded/
>> loaded, so
>> libperl/Perl goes away with it.
>>
>> This is a flaw in the documentation, I suspect. Keep in mind that most
>> mod_perl 1.x users use static compilation, so the DSO case is not very
>> common.
>
> Yeah, but not so in mod_perl2. And 30 seconds is an awfully long time
> to wait for a startup…is there nothing I can do to reduce the start
> time?

Not without more profiling to try and figure out where all this time
is being spent.

--
Philippe M. Chiasson GPG: F9BFE0C2480E7680 1AE53631CB32A107 88C3A5A5
http://gozer.ectoplasm.org/ m/gozer\@(apache|cpan|ectoplasm)\.org/
Attachments: signature.asc (0.18 KB)


david at kineticode

Apr 10, 2009, 2:13 PM

Post #16 of 17 (4918 views)
Permalink
Re: Startup Slow with DSO mod_perl [In reply to]
On Apr 10, 2009, at 11:38 AM, Philippe M. Chiasson wrote:

> Not without more profiling to try and figure out where all this time
> is being spent.

Stupid question: Can you suggest some approaches to doing such
profiling? I mean, I can use Devel::NYTProf or something for the Perl
code, but I don't know about the Apache side of things…

Thanks,

David
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe[at]perl.apache.org
For additional commands, e-mail: dev-help[at]perl.apache.org


gozer at ectoplasm

Apr 20, 2009, 9:11 PM

Post #17 of 17 (4686 views)
Permalink
Re: Startup Slow with DSO mod_perl [In reply to]
On 10/04/09 17:13 , David E. Wheeler wrote:
> On Apr 10, 2009, at 11:38 AM, Philippe M. Chiasson wrote:
>
>> Not without more profiling to try and figure out where all this time
>> is being spent.
>
> Stupid question: Can you suggest some approaches to doing such
> profiling? I mean, I can use Devel::NYTProf or something for the Perl
> code, but I don't know about the Apache side of things…

oprofile is a good Linux system profiling tool, then there are the more
usual suspects:

- strace
- ltrace
- ftrace

Personally, I usually often end up starting with a Perl-level profiler,
like Devel::NYTProf, and some help from strace to see where the difference
is. If it requires more digging (like time spend *outside* perl itself),
a healthy mix of the above tool with some custom aggregating scripts
works for me.

Hope this helps.

--
Philippe M. Chiasson GPG: F9BFE0C2480E7680 1AE53631CB32A107 88C3A5A5
http://gozer.ectoplasm.org/ m/gozer\@(apache|cpan|ectoplasm)\.org/
Attachments: signature.asc (0.18 KB)

ModPerl dev RSS feed   Index | Next | Previous | View Threaded
 
 


Interested in having your list archived? Contact lists@gossamer-threads.com
 
  Web Applications & Managed Hosting Powered by Gossamer Threads Inc.