[solved] Retry with new instance.

[mistwang]

Please download and try 4.0.20 build, we add some logic to avoid that.
Just change version number in the download link.

[IanD]

I've running 4.0.20 now BUT.. I'm afraid the same problem.

After exactly 40 seconds I see the 2nd duplicate mysql query appear and these log file lines start appearing about ~ 35 seconds:

2011-02-22 01:37:57.101 [NOTICE] [89.238.173.***:4680-0#APVH_] Content len: 0, Request line: 'GET /test.php HTTP/1.1'
2011-02-22 01:38:07.004 [NOTICE] [89.241.216.*:15913-0#APVH_] No request delivery notification has been received from LSAPI process:15512, possible run away process.
2011-02-22 01:38:07.005 [NOTICE] [89.241.216.*:15913-0#APVH_] Retry with new instance.

I'm 89.238.173.***

[mistwang]

if "LSAPI_ACCEPT_NOTIFY" env is set in your lsphp5 external app configuration, you need to remove it.

[mistwang]

And you should rebuild PHP with latest LSAPI v5.5

[IanD]

I had actually rebuilt PHP before my last test, so it was:

Server API LiteSpeed V5.5

And I never put LSAPI_ACCEPT_NOTIFY in the env before.

[mistwang]

2011-02-22 01:38:07.004 [NOTICE] [89.241.216.*:15913-0#APVH_] No request delivery notification has been received from LSAPI process:15512, possible run away process.

This is request from another user, the request was assigned to a run away PHP process (stuck with the long MySQL query, maybe). It has to be retried with another good PHP process, it has nothing to do with the second SQL you observed.

You should only look for your IP for anything related to your test script.
If you test script return a 503 error or 408 timeout, there should be no retries.

LiteSpeed does not kill the PHP process running the long SQL, as it is dangerous, may corrupt mysql DB. So, it will run until the SQL finishes.

4.0.20 does not retry a request if it has been in process for more than 30 seconds.

[IanD]

I'm afraid that's just not what I'm seeing here, I've installed 4.0.20

I can replicate it every time, I'd be happy to show you.

Here's another log - this time I added a

PHP Code:

error_log('DEBUG LINE - STARTED PROCESS'); 


at the start of the test script.

2011-02-23 00:40:28.254 [NOTICE] [89.238.173.***:2161-0#APVH_] [STDERR] DEBUG LINE - STARTED PROCESS
2011-02-23 00:40:59.202 [NOTICE] [89.238.173.***:2161-0#APVH_] Content len: 0, Request line: 'GET /test.php?ian=1 HTTP/1.1'
2011-02-23 00:41:09.004 [NOTICE] [110.136.190.***:10354-0#APVH_] No request delivery notification has been received from LSAPI process:6870, possible run away process.
2011-02-23 00:41:09.004 [NOTICE] [110.136.190.***:10354-0#APVH_] Retry with new instance.
2011-02-23 00:41:09.110 [NOTICE] [89.238.173.***:2176-0#APVH_] [STDERR] DEBUG LINE - STARTED PROCESS
2011-02-23 00:41:30.502 [NOTICE] [89.238.173.***:2176-0#APVH_] Content len: 0, Request line: 'GET /test.php?ian=1 HTTP/1.1'
2011-02-23 00:41:40.006 [NOTICE] [223.204.158.***:53244-0#APVH_] No request delivery notification has been received from LSAPI process:5799, possible run away process.
2011-02-23 00:41:40.006 [NOTICE] [223.204.158.***:53244-0#APVH_] Retry with new instance.
2011-02-23 00:41:40.110 [NOTICE] [89.238.173.***:2189-0#APVH_] [STDERR] DEBUG LINE - STARTED PROCESS
2011-02-23 00:42:01.150 [NOTICE] [89.238.173.***:2189-0#APVH_] Content len: 0, Request line: 'GET /test.php?ian=1 HTTP/1.1'
2011-02-23 00:42:11.185 [NOTICE] [67.228.245.***:52077-0#APVH_] No request delivery notification has been received from LSAPI process:6920, possible run away process.
2011-02-23 00:42:11.185 [NOTICE] [67.228.245.***:52077-0#APVH_] Retry with new instance.
2011-02-23 00:42:12.109 [NOTICE] [89.238.173.***:2204-0#APVH_] [STDERR] DEBUG LINE - STARTED PROCESS

As you can see almost instantly after a 'Retry with new instance' (logged with a different IP address) my script is started again. I know you say only look at log entries for my IP - but that's too much of a coincidence.

And it had been in process for more than 30 seconds, seems to be at 31 or 32 seconds it is restarted. At the end of this I had 4 identical MySql queries running.

Not sure what else I can do!!

Thanks for your help.

[mistwang]

2011-02-23 00:40:28.254 [notice] [89.238.173.***:2161-0#apvh_] [stderr] debug line - started process
2011-02-23 00:41:09.110 [notice] [89.238.173.***:2176-0#apvh_] [stderr] debug line - started process
2011-02-23 00:41:40.110 [notice] [89.238.173.***:2189-0#apvh_] [stderr] debug line - started process
2011-02-23 00:42:12.109 [notice] [89.238.173.***:2204-0#apvh_] [stderr] debug line - started process

You should notice that each log entry has a different port number
2161, 2176, 2189, 2204, it means that the client you use for this test was resending the same request repeatedly, if the same request being restarted multiple times, the port number will stay the same.

[IanD]

Interesting. Obviously I'm not sat here hitting the F5 key

Just tried it in IE (was using Firefox before) and guess what, you were correct, no duplicate mysql query. Get the same log lines at 30 seconds (retry with new instance etc) but the php script is not reloaded. IE has a 408 Request Time-out page, not something I've seen before but this all sounds like this is the correct behavior. Perfect.

Just need to need to work out the difference with Firefox then - I've never come across something like this before.

Would Firefox automatically refresh the URL if it's sent a 408 Request time out header? That's what seems to be happening. If it is it does it very quietly because FireBug doesn't pick it up.

Now looking carefully for a split second I can see in the status bar of Firefox at 30 seconds making a new request. Also tried with all add-ons and plug-ins disabled.

[NiteWave]

in firefox's URL, keyin: about:config
then search retry,I got 2 settings:
network.proxy.autoconfig_retry_interval_max;300
network.proxy.autoconfig_retry_interval_min;5

not sure if it's related.