Re: [Mod-fcgid-users] Debian Etch: Strange delay upon first start of fcgi-application (PHP)
On 03/11/2008 7:01:59 PM +0100, Tobias Wiersch <[EMAIL PROTECTED]> wrote: > first of all: I solved it. very glad to see it's working! > Debian is a "little" conservative with the upgrade of versions. > So Sarge is running the old 1.05 and Etch (latest Debian-release!) is > running the old 1.10. > Phew... Do they even use Apache 2.x ? (OK I'm really not a Debian guy :)) But they would better not make a package for mod_fcgid if they can't maintain it, or maybe popping a "old and unmaintained" message before installing such a package because the last 1.x release was 2 years ago! (BTW, from the changelog: "avoid the 1-second sleep the first time a process is spawned". I didn't figured it out, because I was sure you had a 2.x version) It may be obvious, but there is major changes between 1.x and 2.x. The rule of thumb with this kind of software (I mean, not sponsored, without official binaries) is to get the last version before trying anything else. Anyway, I hope you will enjoy using the current version without additionnal bugs. Tell us if you have any. Gabriel - This SF.net email is sponsored by: Microsoft Defy all challenges. Microsoft(R) Visual Studio 2008. http://clk.atdmt.com/MRT/go/vse012070mrt/direct/01/ ___ Mod-fcgid-users mailing list Mod-fcgid-users@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/mod-fcgid-users
Re: [Mod-fcgid-users] Debian Etch: Strange delay upon first start of fcgi-application (PHP)
Hi Gabriel, first of all: I solved it. Gabriel Barazer schrieb: > > can you tell what is the mod_fcgid version on each server? If the > version is the same, you may be facing the same bug on each server, but > for some reason it's not triggered on Debian Sarge. > Debian is a "little" conservative with the upgrade of versions. So Sarge is running the old 1.05 and Etch (latest Debian-release!) is running the old 1.10. Phew... > very good to know, except if the module on etch is an old version. Have > you set the same fcgid directives in your apache configuration? > Yes, same directives. Because Debian Etch is running the old 1.10, I compiled the current version by myself. After I figured out that I have to use --with-suexec-bin and SharememPath, I was able to install the new module. :-) And it worked! Just for the records: First request: real0m0.056s Second request: real0m0.007s Very great ... thanks for the help. Tobias - This SF.net email is sponsored by: Microsoft Defy all challenges. Microsoft(R) Visual Studio 2008. http://clk.atdmt.com/MRT/go/vse012070mrt/direct/01/ ___ Mod-fcgid-users mailing list Mod-fcgid-users@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/mod-fcgid-users
Re: [Mod-fcgid-users] Debian Etch: Strange delay upon first start of fcgi-application (PHP)
On 03/10/2008 7:53:10 PM +0100, Tobias Wiersch <[EMAIL PROTECTED]> wrote: >> > Yes, the results were from 2 servers. > The Etch-server has the problem. I wrote the results from the sarge > server only to show the difference. can you tell what is the mod_fcgid version on each server? If the version is the same, you may be facing the same bug on each server, but for some reason it's not triggered on Debian Sarge. Anyway, if it's a bug and we have to relase an update, you'll have to compile from source and not from packages... >> What you need to do to isolate the problem is leave PHP alone because >> you have the start delay even without it. calling exit() within suexec >> or returning just before the execv is a good test case. >> Can you test on your 2 servers with the patched suexec? Test multiple >> times with apache stop or reboot commands between to be sure the delay >> is the same. > Ok, on Etch: > real0m1.010s > (always the same because the fastcgi-link to php can't be established > because of the exit() at the beginning of suexec) very good to know, except if the module on etch is an old version. Have you set the same fcgid directives in your apache configuration? > > On Sarge: > real0m0.005s > (same patched suexec) >> Are you installing mod_fcgid with the automated system (apt-get) or >> compiling from source? > I use the standard-debian package because I don't want to re-compile the > packages after every security fix. > Do you think the problem is fixed in the later releases? AFAIK Etch is newer than Sarge (I'm *really* not a Debian expert, made my own OS), so the fcgid module is probably newer as well. Last version is 2.2 and some hardcoded variables related to the scoring (the mechanism which determines if a new fastcgi application has to be spawned) have been changed. BTW, have you got anything related to mod_fcgid in your error log? You have to log some info or debug level errors in your apache config. Maybe you will find some interesting stuff. Gabriel - This SF.net email is sponsored by: Microsoft Defy all challenges. Microsoft(R) Visual Studio 2008. http://clk.atdmt.com/MRT/go/vse012070mrt/direct/01/ ___ Mod-fcgid-users mailing list Mod-fcgid-users@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/mod-fcgid-users
Re: [Mod-fcgid-users] Debian Etch: Strange delay upon first start of fcgi-application (PHP)
Hi Gabriel, Gabriel Barazer schrieb: > > I'm confused. Is it the same server, same kernel & other > hardware/software specs ? If you try 2 different debian distrubtion, > there may be some changes in PHP/libraries. > Yes, the results were from 2 servers. The Etch-server has the problem. I wrote the results from the sarge server only to show the difference. > What you need to do to isolate the problem is leave PHP alone because > you have the start delay even without it. calling exit() within suexec > or returning just before the execv is a good test case. > Can you test on your 2 servers with the patched suexec? Test multiple > times with apache stop or reboot commands between to be sure the delay > is the same. Ok, on Etch: real0m1.010s (always the same because the fastcgi-link to php can't be established because of the exit() at the beginning of suexec) On Sarge: real0m0.005s (same patched suexec) > Are you installing mod_fcgid with the automated system (apt-get) or > compiling from source? I use the standard-debian package because I don't want to re-compile the packages after every security fix. Do you think the problem is fixed in the later releases? Tobias - This SF.net email is sponsored by: Microsoft Defy all challenges. Microsoft(R) Visual Studio 2008. http://clk.atdmt.com/MRT/go/vse012070mrt/direct/01/ ___ Mod-fcgid-users mailing list Mod-fcgid-users@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/mod-fcgid-users
Re: [Mod-fcgid-users] Debian Etch: Strange delay upon first start of fcgi-application (PHP)
On 03/10/2008 3:19:16 PM +0100, Tobias Wiersch <[EMAIL PROTECTED]> wrote: > > Gabriel Barazer schrieb: >> 1) Is the delay *exactly* 2 seconds when calling a PHP script (before >> getting the http error 500 from your suexec test) ? Or is there another >> additionnal delay to look for ? >> > I think it is a 1 second delay. > I made a "time wget http://localhost/testxxx.php"; to circumvent network > latency (after a apache reload). > Result1: real0m1.054s > Result2: real0m1.056s > (unpatched suexec, php was normally loaded, script contained only an "echo") > > Subsequent requests: > Result1: real0m0.008s > Result2: real0m0.009s > > And the results from a server running under Debian Sarge instead of Etch > (the Etch server is actually much faster and the Sarge server slower - > but the results for the first call are nonetheless 10 times better under > Sarge!?) > first call: real0m0.119s > second call: real0m0.023s I'm confused. Is it the same server, same kernel & other hardware/software specs ? If you try 2 different debian distrubtion, there may be some changes in PHP/libraries. What you need to do to isolate the problem is leave PHP alone because you have the start delay even without it. calling exit() within suexec or returning just before the execv is a good test case. Can you test on your 2 servers with the patched suexec? Test multiple times with apache stop or reboot commands between to be sure the delay is the same. If it's the same delay, it's likely to be a hardcoded time value; if the delay changes, it can be a library load time or a cache prefetch time. Are you installing mod_fcgid with the automated system (apt-get) or compiling from source? I know many debian users love to use the apt-get system, but this is really not what you want to do to test a specific problem in a specific module version. You have to only modify 1 thing between your tests or you won't be able to isolate the problem. It's like you have a cold AND headaches, and you take 2 different pills: you won't know which one made your headaches disappear. >> Oh, and add something like -s 4096 to the strace command to see more on >> the socket read. >> > > Strace with -s 4096: nothing relevant here Gabriel - This SF.net email is sponsored by: Microsoft Defy all challenges. Microsoft(R) Visual Studio 2008. http://clk.atdmt.com/MRT/go/vse012070mrt/direct/01/ ___ Mod-fcgid-users mailing list Mod-fcgid-users@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/mod-fcgid-users
Re: [Mod-fcgid-users] Debian Etch: Strange delay upon first start of fcgi-application (PHP)
Hi Gabriel,
Gabriel Barazer schrieb:
>
> 1) Is the delay *exactly* 2 seconds when calling a PHP script (before
> getting the http error 500 from your suexec test) ? Or is there another
> additionnal delay to look for ?
>
I think it is a 1 second delay.
I made a "time wget http://localhost/testxxx.php"; to circumvent network
latency (after a apache reload).
Result1: real0m1.054s
Result2: real0m1.056s
(unpatched suexec, php was normally loaded, script contained only an "echo")
Subsequent requests:
Result1: real0m0.008s
Result2: real0m0.009s
And the results from a server running under Debian Sarge instead of Etch
(the Etch server is actually much faster and the Sarge server slower -
but the results for the first call are nonetheless 10 times better under
Sarge!?)
first call: real0m0.119s
second call: real0m0.023s
> Oh, and add something like -s 4096 to the strace command to see more on
> the socket read.
>
Strace with -s 4096:
0.00 poll([{fd=15, events=POLLIN}], 1, 3000) = 0
3.002263 gettimeofday({1205158079, 930678}, NULL) = 0
0.000185 semop(4030464, 0x2b0f4464fda0, 1) = 0
0.000144 semop(4030464, 0x2b0f4464fda6, 1) = 0
0.000119 gettimeofday({1205158079, 931096}, NULL) = 0
0.000123 gettimeofday({1205158079, 931220}, NULL) = 0
0.000124 gettimeofday({1205158079, 931343}, NULL) = 0
0.000123 gettimeofday({1205158079, 931465}, NULL) = 0
0.000124 semop(4030464, 0x2b0f4464fda0, 1) = 0
0.000118 semop(4030464, 0x2b0f4464fda6, 1) = 0
0.000119 semop(4030464, 0x2b0f4464fda0, 1) = 0
0.000117 semop(4030464, 0x2b0f4464fda6, 1) = 0
0.000118 poll([{fd=15, events=POLLIN, revents=POLLIN}], 1, 3000) = 1
1.358629 read(15,
"/home/xxx.de/htdocs/testxxx.php\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0/usr/bin/php5-cgi\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\371\3?\0\0\0\0
\0\1\t\0\0\0\0\0\0\377\377\377\377\377\377\377\377\352\3\0\0\350\3\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\
0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0
\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\
Re: [Mod-fcgid-users] Debian Etch: Strange delay upon first start of fcgi-application (PHP)
On 03/10/2008 1:38:36 PM +0100, Tobias Wiersch <[EMAIL PROTECTED]> wrote:
> Hi Gabriel,
>
> Gabriel Barazer schrieb:
>> I suppose this command is an init script and really does "apachectl -k
>> graceful" ? Can you confirm this ? Since these init scripts are not part
>> of the apache distribution, we don't know *exactly* what they do and
>> there _is_ a big difference between the "-k graceful" and "-k restart"
>> command for example.
>>
> I checked it: the debian script will do a "graceful" restart.
>
>> then: strace -ff -r -p .
>>
> Uh, sorry, my last strace was without -ff ... I'm not familiar with strace.
> Here it comes again:
>
> =
> Traced process 1:
>
> 0.00 poll([{fd=15, events=POLLIN, revents=POLLIN}], 1, 3000) = 1
> 2.180921 read(15, "/home/xxx.de/htdocs/testxxx.php"..., 12840) = 12840
OK, this means the fcgid PM is sending 12840 bytes over the socket (fd
15 in your case is probably the fastcgi socket listened).
1) Is the delay *exactly* 2 seconds when calling a PHP script (before
getting the http error 500 from your suexec test) ? Or is there another
additionnal delay to look for ?
2) have you tried to do the same using a localhost connection? e.g using
time ab -c 1 -n 1
Because fcgid has a major design flaw by buffering the data between
apache and the fastcgi process, the delay could come from this buffering
step. You don't have any network delay when sending data over localhost
so if the problem is related to buffering, this test would confirm it.
Oh, and add something like -s 4096 to the strace command to see more on
the socket read.
Gabriel
-
This SF.net email is sponsored by: Microsoft
Defy all challenges. Microsoft(R) Visual Studio 2008.
http://clk.atdmt.com/MRT/go/vse012070mrt/direct/01/
___
Mod-fcgid-users mailing list
Mod-fcgid-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/mod-fcgid-users
Re: [Mod-fcgid-users] Debian Etch: Strange delay upon first start of fcgi-application (PHP)
Hi Gabriel,
Gabriel Barazer schrieb:
>
> I suppose this command is an init script and really does "apachectl -k
> graceful" ? Can you confirm this ? Since these init scripts are not part
> of the apache distribution, we don't know *exactly* what they do and
> there _is_ a big difference between the "-k graceful" and "-k restart"
> command for example.
>
I checked it: the debian script will do a "graceful" restart.
> then: strace -ff -r -p .
>
Uh, sorry, my last strace was without -ff ... I'm not familiar with strace.
Here it comes again:
=
Traced process 1:
0.00 poll([{fd=15, events=POLLIN, revents=POLLIN}], 1, 3000) = 1
2.180921 read(15, "/home/xxx.de/htdocs/testxxx.php"..., 12840) = 12840
0.000123 semop(2949120, 0x2b0f4464fda0, 1) = 0
0.59 semop(2949120, 0x2b0f4464fda6, 1) = 0
0.45 gettimeofday({1205152227, 133407}, NULL) = 0
0.000105 unlink("/var/lib/apache2/fcgid/sock/4190.0") = -1 ENOENT
(No such file or directory)
0.000133 socket(PF_FILE, SOCK_STREAM, 0) = 16
0.81 umask(077)= 022
0.46 bind(16, {sa_family=AF_FILE,
path="/var/lib/apache2/fcgid/sock/4190.0"}, 110) = 0
0.000144 umask(022)= 077
0.41 listen(16, 5) = 0
0.40 geteuid() = 33
0.000122 pipe([17, 19])= 0
0.73 dup2(9, 17) = 17
0.48 pipe([20, 21])= 0
0.50 dup2(9, 20) = 20
0.49 pipe([22, 23])= 0
0.61 dup2(16, 22) = 22
0.61 gettimeofday({1205152227, 134460}, NULL) = 0
0.97 write(9, "[Mon Mar 10 13:30:27 2008] [noti"..., 116) = 116
0.000105 clone(Process 4195 attached
child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0x2b0f45f92650) = 4195
[pid 4190] 0.000793 close(22
[pid 4195] 0.000341 close(14
[pid 4190] 0.29 <... close resumed> ) = 0
[pid 4190] 0.26 close(20) = 0
[pid 4190] 0.42 close(17) = 0
[pid 4190] 0.63 close(16) = 0
[pid 4190] 0.60 semop(2949120, 0x2b0f4464fda0, 1) = 0
[pid 4190] 0.52 semop(2949120, 0x2b0f4464fda6, 1) = 0
[pid 4190] 0.64 gettimeofday({1205152227, 136132}, NULL) = 0
[pid 4190] 0.65 write(9, "[Mon Mar 10 13:30:27 2008]
[noti"..., 101) = 101
[pid 4190] 0.85 gettimeofday({1205152227, 136283}, NULL) = 0
[pid 4190] 0.67 write(18, "p", 1) = 1
[pid 4190] 0.61 gettimeofday({1205152227, 136406}, NULL) = 0
[pid 4190] 0.63 semop(2949120, 0x2b0f4464fda0, 1) = 0
[pid 4190] 0.52 semop(2949120, 0x2b0f4464fda6, 1) = 0
[pid 4190] 0.49 gettimeofday({1205152227, 136573}, NULL) = 0
[pid 4190] 0.53 gettimeofday({1205152227, 136624}, NULL) = 0
[pid 4190] 0.52 gettimeofday({1205152227, 136675}, NULL) = 0
[pid 4190] 0.51 gettimeofday({1205152227, 136727}, NULL) = 0
[pid 4190] 0.54 semop(2949120, 0x2b0f4464fda0, 1
[pid 4195] 0.33 <... close resumed> ) = 0
[pid 4195] 0.48 close(5
[pid 4190] 0.30 <... semop resumed> ) = 0
[pid 4190] 0.28 semop(2949120, 0x2b0f4464fda6, 1) = 0
[pid 4190] 0.47 semop(2949120, 0x2b0f4464fda0, 1) = 0
[pid 4190] 0.48 semop(2949120, 0x2b0f4464fda6, 1
[pid 4195] 0.47 <... close resumed> ) = 0
[pid 4190] 0.17 <... semop resumed> ) = 0
[pid 4190] 0.28 poll(
[pid 4195] 0.35 close(3) = 0
[pid 4195] 0.43 close(6) = 0
[pid 4195] 0.43 close(4) = 0
[pid 4195] 0.53 close(13) = 0
[pid 4195] 0.54 close(12) = 0
[pid 4195] 0.44 close(11) = 0
[pid 4195] 0.43 close(10) = 0
[pid 4195] 0.43 close(9) = 0
[pid 4195] 0.53 close(8) = 0
[pid 4195] 0.56 close(7) = 0
[pid 4195] 0.70 setresuid(-1, 0, -1) = 0
[pid 4195] 0.50 setuid(33)= 0
[pid 4195] 0.75 close(23) = 0
[pid 4195] 0.50 dup2(22, 0) = 0
[pid 4195] 0.44 close(22) = 0
[pid 4195] 0.42 close(21) = 0
[pid 4195] 0.44 dup2(20, 1) = 1
[pid 4195] 0.44 close(20) = 0
[pid 4195] 0.45 close(19) = 0
[pid 4195] 0.44 dup2(17, 2) = 2
[pid 4195] 0.45 close(17) = 0
[pid 4195] 0.86 rt_sigaction(SIGCHLD, {SIG_DFL}, {SIG_DFL}, 8) = 0
[pid 4195] 0.78 chdir("/usr/bin/") = 0
[pid 4195] 0.000158 execve("/usr/lib/apache2/suexec",
["/usr/lib/apache2/suexec", "1002", "1000", "php5-cgi"], [/* 0 vars */]) = 0
[pid 4195] 0.000824 uname({sys="Linux", node="xxx.xxx.de", ...}) = 0
[pid 4195] 0.000165 brk(0)= 0x804c000
[pid 4195] 0.53 fcntl64(0, F_GETFD) = 0
[pid 4195] 0.49 fcntl64(1, F_GETFD) = 0
[pid 4195] 0
Re: [Mod-fcgid-users] Debian Etch: Strange delay upon first start of fcgi-application (PHP)
Hi Thilo,
Thilo Bangert schrieb:
> okay - interesting. have you tried using strace to check what the
> apache process is doing?
Okay, here comes the strace of apache's PID. Maybe a problem with the
POLLIN-routine?
(thanks in advance for your help)
0.49 poll([{fd=15, events=POLLIN, revents=POLLIN}], 1, 3000) = 1
2.283507 read(15, "/home/xxx.de/htdocs/testxxx.php"..., 12840) = 12840
0.57 semop(1769472, 0x2b0f4464fda0, 1) = 0
0.20 semop(1769472, 0x2b0f4464fda6, 1) = 0
0.18 gettimeofday({1205150049, 128511}, NULL) = 0
0.43 unlink("/var/lib/apache2/fcgid/sock/3819.0") = -1 ENOENT
(No such file or directory)
0.62 socket(PF_FILE, SOCK_STREAM, 0) = 16
0.34 umask(077)= 022
0.20 bind(16, {sa_family=AF_FILE,
path="/var/lib/apache2/fcgid/sock/3819.0"}, 110) = 0
0.59 umask(022)= 077
0.19 listen(16, 5) = 0
0.16 geteuid() = 33
0.50 pipe([17, 19])= 0
0.33 dup2(9, 17) = 17
0.21 pipe([20, 21])= 0
0.21 dup2(9, 20) = 20
0.22 pipe([22, 23])= 0
0.23 dup2(16, 22) = 22
0.27 gettimeofday({1205150049, 128962}, NULL) = 0
0.44 write(9, "[Mon Mar 10 12:54:09 2008] [noti"..., 116) = 116
0.44 clone(child_stack=0,
flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0x2b0f45f92650) = 3824
0.000569 close(22) = 0
0.18 close(20) = 0
0.16 close(17) = 0
0.25 close(16) = 0
0.26 semop(1769472, 0x2b0f4464fda0, 1) = 0
0.21 semop(1769472, 0x2b0f4464fda6, 1) = 0
0.26 gettimeofday({1205150049, 129751}, NULL) = 0
0.28 write(9, "[Mon Mar 10 12:54:09 2008] [noti"..., 101) = 101
0.37 gettimeofday({1205150049, 129814}, NULL) = 0
0.26 write(18, "p", 1) = 1
0.23 gettimeofday({1205150049, 129863}, NULL) = 0
0.25 gettimeofday({1205150049, 129888}, NULL) = 0
0.20 gettimeofday({1205150049, 129908}, NULL) = 0
0.21 gettimeofday({1205150049, 129929}, NULL) = 0
0.21 poll(
and another one:
0.48 poll([{fd=15, events=POLLIN, revents=POLLIN}], 1, 3000) = 1
1.099453 read(15, "/home/xxx.de/htdocs/testxxx.php"..., 12840) = 12840
0.000131 semop(2654208, 0x2b0f4464fda0, 1) = 0
0.53 semop(2654208, 0x2b0f4464fda6, 1) = 0
0.49 gettimeofday({1205152018, 613491}, NULL) = 0
0.000103 unlink("/var/lib/apache2/fcgid/sock/4095.0") = -1 ENOENT
(No such file or directory)
0.000141 socket(PF_FILE, SOCK_STREAM, 0) = 16
0.85 umask(077)= 022
0.50 bind(16, {sa_family=AF_FILE,
path="/var/lib/apache2/fcgid/sock/4095.0"}, 110) = 0
0.000150 umask(022)= 077
0.42 listen(16, 5) = 0
0.43 geteuid() = 33
0.000121 pipe([17, 19])= 0
0.81 dup2(9, 17) = 17
0.52 pipe([20, 21])= 0
0.62 dup2(9, 20) = 20
0.57 pipe([22, 23])= 0
0.60 dup2(16, 22) = 22
0.68 gettimeofday({1205152018, 614608}, NULL) = 0
0.000101 write(9, "[Mon Mar 10 13:26:58 2008] [noti"..., 116) = 116
0.000110 clone(child_stack=0,
flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0x2b0f45f92650) = 4100
0.001362 close(22) = 0
0.55 close(20) = 0
0.43 close(17) = 0
0.63 close(16) = 0
0.61 semop(2654208, 0x2b0f4464fda0, 1) = 0
0.54 semop(2654208, 0x2b0f4464fda6, 1) = 0
0.64 gettimeofday({1205152018, 616518}, NULL) = 0
0.65 write(9, "[Mon Mar 10 13:26:58 2008] [noti"..., 101) = 101
0.82 gettimeofday({1205152018, 61}, NULL) = 0
0.66 write(18, "p", 1) = 1
0.59 gettimeofday({1205152018, 616790}, NULL) = 0
0.62 gettimeofday({1205152018, 616852}, NULL) = 0
0.52 gettimeofday({1205152018, 616904}, NULL) = 0
0.52 gettimeofday({1205152018, 616956}, NULL) = 0
0.53 poll(
-
This SF.net email is sponsored by: Microsoft
Defy all challenges. Microsoft(R) Visual Studio 2008.
http://clk.atdmt.com/MRT/go/vse012070mrt/direct/01/
___
Mod-fcgid-users mailing list
Mod-fcgid-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/mod-fcgid-users
Re: [Mod-fcgid-users] Debian Etch: Strange delay upon first start of fcgi-application (PHP)
Hi On 03/10/2008 11:08:14 AM +0100, Tobias Wiersch <[EMAIL PROTECTED]> wrote: > Hello there! > > I'm using mod_fcgid on several servers since Debian Sarge. > On Debian Sarge all is running fine. > But ALL three Etch-servers (1 updated from sarge, 2 freshly installed) > have a delay-problem: > > When I do a "apache2 reload", all spawned PHP-fcgi-tasks will die, which > is normal behaviour. I suppose this command is an init script and really does "apachectl -k graceful" ? Can you confirm this ? Since these init scripts are not part of the apache distribution, we don't know *exactly* what they do and there _is_ a big difference between the "-k graceful" and "-k restart" command for example. > But when I then call a PHP-script from a webpage for the first time, it > will take 1-2 seconds to initialize! When I call the PHP-script again, > it will then load instantly. > > So why there is such a delay at the first call? All my servers with > Sarge don't show this init-delay, only all servers with Etch. > > I first thought that the delay was caused by PHP (loading of all > modules?), but this doesn't seem to apply: > I tried to track down the problem and it seems that it will happen > BEFORE suexec/PHP is loaded. > To verify this, I patched suexec to exit immediatly at start. > When I then load a PHP-script with the patched suexec, the delay is > still there, and after that I receive the 500-Server error. > Furthermore, when I call php5-cgi from the command-line, there is > absolutely no delay. > > So I think the problem is in Apache or mod_fcgid. > Any suggestions? First you have to confirm where the delay is. To do so, you have to trace syscalls with strace. When you start apache (or reloading), take a careful look at the process table and you will see a particular httpd process which is the mod_fcgid process manager. This is the process responsible for spawning the fastcgi apps (through the suexec wrapper if necessary). To see exactly where is the delay, you have to identify the process ID of the process manager (hint: the memory consumed by this process is slightly different than the other httpd processes, excluding the parent). then: strace -ff -r -p . And post the result here when experiencing the problem. You should have a line indicating the delay with the time counter at the beginning of each line. This will show us where the fcgid process manager is sleeping instead of spawning and yelling at the php processes to do their job. Gabriel - This SF.net email is sponsored by: Microsoft Defy all challenges. Microsoft(R) Visual Studio 2008. http://clk.atdmt.com/MRT/go/vse012070mrt/direct/01/ ___ Mod-fcgid-users mailing list Mod-fcgid-users@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/mod-fcgid-users
Re: [Mod-fcgid-users] Debian Etch: Strange delay upon first start of fcgi-application (PHP)
On Monday 10 March 2008 11:48:30 Tobias Wiersch wrote: > Hi Thilo, > > Thilo Bangert schrieb: > > try calling php from the commandline right before you reload apache... > > Thanks for the quick reply. > But I already tried that. > PHP is definitely in the cache. > # php5-cgi test.php > # /etc/init.d/apache2 reload > Same delay. And I have a very big cache on the machine. > Subsequent calls of "apache2 reload" will also raise the delay. > > And my experiment with suexec clearly (I think) shows that the problem depends on the patch, i suppose ;) > isn't PHP related. Because when the patched suexec exit right at start, > there will no PHP be loaded! But I still experience the delay. okay - interesting. have you tried using strace to check what the apache process is doing? it cant give the full details, but may help to pinpoint the culprit. i dont have time to test this here, right now, but i may look into doing so tonight. does the delay disappear, if you leave out suexec? > Tobias regards Thilo - This SF.net email is sponsored by: Microsoft Defy all challenges. Microsoft(R) Visual Studio 2008. http://clk.atdmt.com/MRT/go/vse012070mrt/direct/01/ ___ Mod-fcgid-users mailing list Mod-fcgid-users@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/mod-fcgid-users
Re: [Mod-fcgid-users] Debian Etch: Strange delay upon first start of fcgi-application (PHP)
Hi Thilo, Thilo Bangert schrieb: > try calling php from the commandline right before you reload apache... Thanks for the quick reply. But I already tried that. PHP is definitely in the cache. # php5-cgi test.php # /etc/init.d/apache2 reload Same delay. And I have a very big cache on the machine. Subsequent calls of "apache2 reload" will also raise the delay. And my experiment with suexec clearly (I think) shows that the problem isn't PHP related. Because when the patched suexec exit right at start, there will no PHP be loaded! But I still experience the delay. Tobias - This SF.net email is sponsored by: Microsoft Defy all challenges. Microsoft(R) Visual Studio 2008. http://clk.atdmt.com/MRT/go/vse012070mrt/direct/01/ ___ Mod-fcgid-users mailing list Mod-fcgid-users@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/mod-fcgid-users
Re: [Mod-fcgid-users] Debian Etch: Strange delay upon first start of fcgi-application (PHP)
> To verify this, I patched suexec to exit immediatly at start. > When I then load a PHP-script with the patched suexec, the delay is > still there, and after that I receive the 500-Server error. > Furthermore, when I call php5-cgi from the command-line, there is > absolutely no delay. > the delay only occurs the _very first_ time you run php - in which the program will be loaded into ram from the harddisc. so if you bootup your PC and run PHP from the command line you will see the delay the first time, but not for consecutive runs... when you run PHP from commandline after apache already has started PHP once, you are already running from a warm disc cache... let me speculate some more: the fact that you see this behavior when you restart apache may indicate that your servers are under very light load, since otherwise PHP would have been restarted a couple of times during the lifetime of the apache parent and thus would have started from warm disc caches. this may not be true for some workloads where the disc cache is evicted very rapidly (low memory). basically, the reason for the delay is your harddisc, not apache or mod_fcgid or php... this is still all speculation, but if some of what i said is right, you might be able to reduce the latency by priming your cache. try calling php from the commandline right before you reload apache... hth Thilo - This SF.net email is sponsored by: Microsoft Defy all challenges. Microsoft(R) Visual Studio 2008. http://clk.atdmt.com/MRT/go/vse012070mrt/direct/01/ ___ Mod-fcgid-users mailing list Mod-fcgid-users@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/mod-fcgid-users
