503 Errors and Magento

[sophrosyne]

CentOS 5.6 x86_64
Litespeed version 4.1.1
PHP 5.2.17 - LSAPI

We're getting numerous 503 errors on the front end. We've been unable to pinpoint the exact factors needed to reproduce, but this is what we see in the logs when they occur:

2011-06-30 14:42:37.913 [INFO] [192.168.1.120:32248-0#APVH_192.168.1.101_example.com] Connection idle time: 31 while in state: 5 watching for event: 24,close!
2011-06-30 14:42:37.913 [NOTICE] [192.168.1.120:32248-0#APVH_192.168.1.101_example.com] Content len: 199, Request line: 'POST /checkout/onepage/saveOrder/ HTTP/1.1'
2011-06-30 14:42:37.913 [INFO] [192.168.1.120:32248-0#APVH_192.168.1.101_example.com] Cookie len: 514, frontend=sa9k15ghjv6a504bk31ofkkkd3; __utma=37169442.541635472.1309455714.1309455714.1309455714.1; __utmb=37169442.10.10.1309455714; __utmc=37169442; __utmz=37169442.1309455714.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none); PAPVisitorId=58f2d425e678501a5829530d7ea8ab82; PAPVisitorId=58f2d425e678501a5829530d7ea8ab82; __utma=258253276.242757773.1309457565.1309457565.1309457565.1; __utmb=258253276.4.10.1309457565; __utmc=258253276; __utmz=258253276.1309457565.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none)
2011-06-30 14:42:37.913 [NOTICE] [192.168.1.120:32248-0#APVH_192.168.1.101_example.com] Redirect: #1, URL: /index.php
2011-06-30 14:42:37.913 [INFO] [192.168.1.120:32248-0#APVH_192.168.1.101_example.com] HttpExtConnector state: 8, request body sent: 199, response body size: 0, response body sent:0, left in buffer: 0, attempts: 0.
2011-06-30 14:42:47.003 [NOTICE] [192.168.1.120:2672-0#APVH_example.com] No request delivery notification has been received from LSAPI process:31348, possible run away process.
2011-06-30 14:42:47.003 [NOTICE] [192.168.1.120:2672-0#APVH_example.com] Retry with new instance.

I read some forum posts where 503 errors were being triggered by large cookie headers. Could this be a cause?

 

[mistwang]

It is like a problem with your PHP setup. Your cookie length is fine.
You can try turning off all type of cache, then enable one by one.

 

[sophrosyne]

We tried disabling APC, which is the only bytecode cache enabled and still got reports of 503 from our users.

Any other suggestions?

Thanks!

 

[sophrosyne]

Also, can you explain exactly what a 503 error is? It seems to be a pretty generic error, and not very useful for debugging.

 

[mistwang]

503 error means the backend cannot complete the request, is usually caused by PHP crash.
The log section you posted is not a 503 error, but a 500 request timeout.
You can search for "oops" string to locate log entries related to 503.

 

[sophrosyne]

I bumped up the LSAPI process limit from 200 to 1000 as it was recommended I bump it up in the server logs. Shortly after, we received further 503 errors.

2011-07-14 18:27:41.752 [INFO] [207.177.237.4:50365-0#APVH_groworganic.com] connection to [/tmp/lshttpd/APVH_groworganic.com_Suphp.sock.721] on request #2, confirmed, 1, associated process: 1479, running: 1, error: Connection reset by peer!
2011-07-14 18:27:41.752 [INFO] Remove pid: 1479, exitcode: 129
2011-07-14 18:27:47.026 [INFO] Remove pid: 1454, exitcode: 129
2011-07-14 18:27:47.948 [INFO] [207.177.237.4:50365-0#APVH_groworganic.com] connection to [/tmp/lshttpd/APVH_groworganic.com_Suphp.sock.228] on request #12, confirmed, 1, associated process: 1512, running: 1, error: Connection reset by peer!
2011-07-14 18:27:47.949 [NOTICE] [207.177.237.4:50365-0#APVH_groworganic.com] Max retries has been reached, 503!
2011-07-14 18:27:47.949 [INFO] Remove pid: 1512, exitcode: 129
2011-07-14 18:27:47.949 [NOTICE] [207.177.237.4:50365-0#APVH_groworganic.com] oops! 503 Service Unavailable
2011-07-14 18:27:47.949 [NOTICE] [207.177.237.4:50365-0#APVH_groworganic.com] Content len: 0, Request line: 'GET / HTTP/1.1'
2011-07-14 18:27:47.949 [INFO] [207.177.237.4:50365-0#APVH_groworganic.com] Cookie len: 366, frontend=v37d16ikgt0o9fsg5c4pk3qin7; __utma=258253276.50411304.1310680283.1310680283.1310680283.1; __utmb=258253276.16.10.1310680283; __utmc=258253276; __utmz=258253276.1310680283.1.1.utmcsr=google|utmccn=(organic)|utmcmd=organic|utmctr=pleasaant%20valley%20grass%20valley; PAPVisitorId=27ebd117b9fc72c053208ad00e1H7nW0; PAPVisitorId=27ebd117b9fc72c053208ad00e1H7nW0


2011-07-14 18:27:57.362 [INFO] [76.9.76.14:17071-0#APVH_groworganic.com] connection to [/tmp/lshttpd/APVH_groworganic.com_Suphp.sock.039] on request #0, confirmed, 1, associated process: 1541, running: 1, error: Connection reset by peer!
2011-07-14 18:27:57.362 [INFO] Remove pid: 1541, exitcode: 129
2011-07-14 18:28:07.291 [INFO] [76.9.76.14:17071-0#APVH_groworganic.com] connection to [/tmp/lshttpd/APVH_groworganic.com_Suphp.sock.204] on request #5, confirmed, 1, associated process: 1503, running: 1, error: Connection reset by peer!
2011-07-14 18:28:07.291 [NOTICE] [76.9.76.14:17071-0#APVH_groworganic.com] Max retries has been reached, 503!
2011-07-14 18:28:07.291 [INFO] Remove pid: 1503, exitcode: 129
2011-07-14 18:28:07.291 [NOTICE] [76.9.76.14:17071-0#APVH_groworganic.com] oops! 503 Service Unavailable
2011-07-14 18:28:07.291 [NOTICE] [76.9.76.14:17071-0#APVH_groworganic.com] Content len: 0, Request line: 'GET / HTTP/1.1'
2011-07-14 18:28:07.291 [INFO] [76.9.76.14:17071-0#APVH_groworganic.com] Cookie len: 237, frontend=qmkrdmuvsv9idkrqu6a9nq1os0; __utma=258253276.1867436900.1310504094.1310504094.1310682070.2; __utmb=258253276.16.10.1310682070; __utmz=258253276.1310682070.2.2.utmcsr=yahoo|utmccn=(organic)|utmcmd=organic|utmctr=peaceful%20valley


2011-07-14 18:28:25.287 [INFO] [76.9.76.14:17073-0#APVH_groworganic.com] connection to [/tmp/lshttpd/APVH_groworganic.com_Suphp.sock.574] on request #20, confirmed, 1, associated process: 1502, running: 1, error: Connection reset by peer!
2011-07-14 18:28:25.287 [INFO] Remove pid: 1502, exitcode: 129
2011-07-14 18:28:35.321 [INFO] [76.9.76.14:17073-0#APVH_groworganic.com] connection to [/tmp/lshttpd/APVH_groworganic.com_Suphp.sock.766] on request #14, confirmed, 1, associated process: 1511, running: 0, error: Connection reset by peer!
2011-07-14 18:28:35.321 [INFO] Remove pid: 1511, exitcode: 129
2011-07-14 18:28:45.264 [INFO] [76.9.76.14:17073-0#APVH_groworganic.com] connection to [/tmp/lshttpd/APVH_groworganic.com_Suphp.sock.744] on request #54, confirmed, 1, associated process: 1463, running: 1, error: Connection reset by peer!
2011-07-14 18:28:45.264 [NOTICE] [76.9.76.14:17073-0#APVH_groworganic.com] Max retries has been reached, 503!
2011-07-14 18:28:45.264 [INFO] Remove pid: 1463, exitcode: 129
2011-07-14 18:28:45.264 [NOTICE] [76.9.76.14:17073-0#APVH_groworganic.com] oops! 503 Service Unavailable
2011-07-14 18:28:45.264 [NOTICE] [76.9.76.14:17073-0#APVH_groworganic.com] Content len: 0, Request line: 'GET / HTTP/1.1'
2011-07-14 18:28:45.264 [INFO] [76.9.76.14:17073-0#APVH_groworganic.com] Cookie len: 237, frontend=qmkrdmuvsv9idkrqu6a9nq1os0; __utma=258253276.1867436900.1310504094.1310504094.1310682070.2; __utmb=258253276.16.10.1310682070; __utmz=258253276.1310682070.2.2.utmcsr=yahoo|utmccn=(organic)|utmcmd=organic|utmctr=peaceful%20valley


It's very frustrating when a product does not provide useful error messages. You mentioned that it was a PHP problem, but we're using LSAPI (a litespeed product) and the PHP binaries work without any problems when Apache is re-enabled.

Any advice you can provide is greatly appreciated.

thank you,

 

[mistwang]

You need to compare phpinfo() page form Apache and LiteSpeed, make sure the configuration options are matched, if not, you need to rebuild PHP.
also check stderr.log for errors.