Stas Bekman wrote:
Steve Hay wrote:
With the LogLevel set appropriately, I actually get the message coming out *four* times when I start the server:
[Tue Sep 16 09:22:43 2003] [info] mod_perl: using Perl HASH_SEED: 2294822312
[Tue Sep 16 09:22:44 2003] [info] mod_perl: using Perl HASH_SEED: 3042930004
[Tue Sep 16 09:22:44 2003] [notice] Parent: Created child process 2336
[Tue Sep 16 09:22:44 2003] [debug] mpm_winnt.c(505): Parent: Sent the scoreboard to the child
[Tue Sep 16 09:22:45 2003] [info] mod_perl: using Perl HASH_SEED: 3745517160
[Tue Sep 16 09:22:46 2003] [info] mod_perl: using Perl HASH_SEED: 370731127
[Tue Sep 16 09:22:46 2003] [notice] Child 2336: Child process is running
...
Is that as expected? I was only expecting to see it once, or maybe once in the parent and once in the child, but I'm sure I'm just missing something.
Interesting. It should happen twice, but for a different reason: apache restarts itself once it's started. See: http://perl.apache.org/docs/2.0/user/handlers/server.html#Startup_Phases_Demonstration_Module
Do you get the PostConfig handler run four times as well?
I wonder why does it run 4 times instead of 2. Moreover it reports 4 different hash seed values, whereas it should differ only between start and restart (but since I don't know where the other two calls came from i can't tell). I tested with worker mpm and it does only 2. may be its a winnt mpm that does that on purpose, or may be it's a bug in that mpm?
I installed the demo module referred to by your link above and yes, the PostConfigHandler does run four times. Here's startup.log which that module produced (I just started the server, paused, and then stopped it):
I did know you could pause the server ;)
[Tue Sep 16 10:25:16 2003] - open_logs : process 1128 is born to reproduce [Tue Sep 16 10:25:16 2003] - post_config: configuration is completed [Tue Sep 16 10:25:17 2003] - END : process 1128 is shutdown [Tue Sep 16 10:25:17 2003] - END : process 1128 is shutdown [Tue Sep 16 10:25:17 2003] - END : process 1128 is shutdown [Tue Sep 16 10:25:17 2003] - END : process 1128 is shutdown [Tue Sep 16 10:25:17 2003] - open_logs : process 1128 is born to reproduce [Tue Sep 16 10:25:17 2003] - post_config: configuration is completed [Tue Sep 16 10:25:19 2003] - open_logs : process 956 is born to reproduce [Tue Sep 16 10:25:19 2003] - post_config: configuration is completed [Tue Sep 16 10:25:19 2003] - END : process 956 is shutdown [Tue Sep 16 10:25:19 2003] - END : process 956 is shutdown [Tue Sep 16 10:25:19 2003] - END : process 956 is shutdown [Tue Sep 16 10:25:19 2003] - END : process 956 is shutdown [Tue Sep 16 10:25:20 2003] - open_logs : process 956 is born to reproduce [Tue Sep 16 10:25:20 2003] - post_config: configuration is completed [Tue Sep 16 10:25:21 2003] - child_init : process 956 is born to serve [Tue Sep 16 10:25:36 2003] - child_exit : process 956 now exits [Tue Sep 16 10:25:36 2003] - END : process 956 is shutdown [Tue Sep 16 10:25:36 2003] - END : process 956 is shutdown [Tue Sep 16 10:25:36 2003] - END : process 956 is shutdown [Tue Sep 16 10:25:36 2003] - END : process 956 is shutdown [Tue Sep 16 10:25:36 2003] - END : process 1128 is shutdown [Tue Sep 16 10:25:36 2003] - END : process 1128 is shutdown [Tue Sep 16 10:25:36 2003] - END : process 1128 is shutdown [Tue Sep 16 10:25:36 2003] - END : process 1128 is shutdown
(Don't you just love the way in which Windoze immediately re-uses the same PID?)
There seems to be slight excess of END's in there too!
Good / bad / don't-know?
Totally unexpected, try that quickly hacked version of say() so we can see the threads as well.
sub say {
my($caller) = (caller(1))[3] =~ /([^:]+)$/;
my $tid = APR::OS::thread_current();
if (defined $log_fh) {
printf $log_fh "[%s] - %-11s: [%s] %s\n",
scalar(localtime), $caller, $$tid, $_[0];
}
else {
# when the log file is not open
warn __PACKAGE__ . " says: $_[0]\n";
}
}I've appended the [$tid] before the original message.
I've tried it with worker :
[Tue Sep 16 11:36:13 2003] - open_logs : [16384] process 14499 is born to reproduce
[Tue Sep 16 11:36:14 2003] - post_config: [16384] configuration is completed
[Tue Sep 16 11:36:15 2003] - END : [16384] process 14499 is shutdown
[Tue Sep 16 11:36:15 2003] - END : [16384] process 14499 is shutdown
[Tue Sep 16 11:36:15 2003] - END : [16384] process 14499 is shutdown
[Tue Sep 16 11:36:15 2003] - END : [16384] process 14499 is shutdown
[Tue Sep 16 11:36:15 2003] - open_logs : [16384] process 14501 is born to reproduce
[Tue Sep 16 11:36:15 2003] - post_config: [16384] configuration is completed
[Tue Sep 16 11:36:16 2003] - child_init : [16384] process 14503 is born to serve
httpd -k stop was issued here
[Tue Sep 16 11:36:21 2003] - child_exit : [16384] process 14503 exits [Tue Sep 16 11:36:21 2003] - END : [16384] process 14501 is shutdown
[Tue Sep 16 11:36:21 2003] - END : [16384] process 14501 is shutdown
[Tue Sep 16 11:36:21 2003] - END : [16384] process 14501 is shutdown
[Tue Sep 16 11:36:21 2003] - END : [16384] process 14501 is shutdown
and it seems to do the right thing regarding the phases execution, but for some reason runs the END block four times, which is not quite right. More things to investigate...
the 16384 number stands for the thread number when threads aren't running yet (i.e. that just the parent process thread in win32 lingo?).
Besides this issue, is there anything else on win32 that the current modperl-2.0 cvs has problems with? e.g. try running t/SMOKE (might want to add -verbose) to smoke it a bit...
Sadly, t/SMOKE doesn't run at all -- see my mail on the other thread about filter tests.
well, it make sense to run t/SMOKE only if 'make test' passes. If it doesn't t/SMOKE will report the same problems and probably won't discover new ones.
__________________________________________________________________ Stas Bekman JAm_pH ------> Just Another mod_perl Hacker http://stason.org/ mod_perl Guide ---> http://perl.apache.org mailto:[EMAIL PROTECTED] http://use.perl.org http://apacheweek.com http://modperlbook.org http://apache.org http://ticketmaster.com
--------------------------------------------------------------------- To unsubscribe, e-mail: [EMAIL PROTECTED] For additional commands, e-mail: [EMAIL PROTECTED]
