8

I am programming a REST API with Zend framework.
When calling the url several times (e.g. 1000 times with 1 request per second), in about 0.2 % of the cases instead of getting 200 OK as a response I get 302 Found - so a redirect to a different page.
Here is the entire server response:

302 Found Date: Mon, 04 Mar 2013 11:56:04 GMT
Server: Apache/2.2.17 (Ubuntu)
X-Powered-By: PHP/5.3.5-1ubuntu7.11
Set-Cookie: PHPSESSID=ui9r8jqa63dbom8osknso6eea5; path=/
Expires: Thu, 19 Nov 1981 08:52:00 GMT
Cache-Control: no-store, no-cache, must-revalidate, post-check=0, pre-check=0
Pragma: no-cache
Location: /de/default/index/index/error/500
Vary: Accept-Encoding
Content-Length: 0
Content-Type: text/html; charset=utf-8

So Zend redirects to the error 500 (internal server error) page. The question is why - and I just can't figure it out...
The php page that is called inserts one row into a MySQL database and returns a JSON string - that's all.

Apache2 has about 20 concurrent connections open and the server load is <<1 so I really do not understand why the requests cause problems.

I know this is a really difficult problem to remote diagnose, but good guesses and recommendations how to solve this are more than welcome! Thanks.

This is the apache vhost config as requested by @chris:

<IfModule mod_ssl.c>
<VirtualHost mydomain.tld:443>
    ServerAdmin webmaster@localhost

    DocumentRoot /var/www
    ServerName www.mydomain.tld
    ServerAlias mydomain.tld *.mydomain.tld
    <Directory />
        Options FollowSymLinks
        AllowOverride All
    </Directory>
    <Directory /var/www/>
        Options Indexes FollowSymLinks MultiViews
        AllowOverride All
        Order allow,deny
        allow from all
    </Directory>

    ScriptAlias /cgi-bin/ /usr/lib/cgi-bin/
    <Directory "/usr/lib/cgi-bin">
        AllowOverride None
        Options +ExecCGI -MultiViews +SymLinksIfOwnerMatch
        Order allow,deny
        Allow from all
    </Directory>

    ErrorLog /var/log/apache2/error.log

    # Possible values include: debug, info, notice, warn, error, crit,
    # alert, emerg.
    LogLevel warn

    CustomLog /var/log/apache2/ssl_access.log combined

#   RewriteLog "/var/log/htaccess.log"
#   RewriteLogLevel 5

    Alias /doc/ "/usr/share/doc/"
    <Directory "/usr/share/doc/">
        Options Indexes MultiViews FollowSymLinks
        AllowOverride None
        Order deny,allow
        Deny from all
        Allow from 127.0.0.0/255.0.0.0 ::1/128
    </Directory>

    #   SSL Engine Switch:
    #   Enable/Disable SSL for this virtual host.
    SSLEngine on
    SSLOptions +StrictRequire
    SSLCertificateFile /etc/apache2/ssl/cert_2013_2014.crt
    SSLCertificateKeyFile /etc/apache2/ssl/www.mydomain.tld.key
    SSLCACertificateFile /etc/apache2/ssl/intermediate.crt

</VirtualHost>
</IfModule>
Horen
  • 11,184
  • 11
  • 71
  • 113
  • What URL are you hitting to test this? Does your API do any redirects normally? – Tim Fountain Mar 04 '13 at 12:52
  • No redirects are usually done. The response is usually `200 OK`. The error occurs even though the script that is calling the url stays exactly the same. – Horen Mar 04 '13 at 12:53
  • What's the text after the last header line (Content-Type: ...) ? The response body ? It is a strange syntax... not json, not a php dump... Else, having X-Powered-By: PHP indicates the redirection comes from php (not from apache). – voondo Mar 06 '13 at 17:05
  • 1
    I assume apache error log says nothing? – fsw Mar 06 '13 at 18:12
  • no, no errors logged. @voondo: I updated the response, it was two dumps. The second one was a dump of a json object. – Horen Mar 06 '13 at 18:21
  • This is very likely a timeout issue. Open up Firebug or a debugger and look at the HTTP headers that are grabbing this URL and see what the timeout parameter is set to. – Alex W Mar 06 '13 at 18:29
  • @AlexW I can't reproduce it "manually" - only if I call the API several times per second e.g. with curl – Horen Mar 06 '13 at 18:31
  • @Horen So what I am saying is what is the timeout of your cURL requests set to? – Alex W Mar 06 '13 at 19:22
  • 1
    ZF should never _redirect_ to an error page, that's why I asked if your API did any redirects elsewhere. It seems like an error is being generated but the error isn't being handled correctly. Do you have any error handling code in your API? Are you using Zend_Rest_Server? – Tim Fountain Mar 07 '13 at 01:00
  • Perhaps every now an then there's an exception which you aren't handling? Try surrounding everything with a `try { ... } catch (...) { echo 'Gotcha!'; }` or roll your own error handler to see if it's the case – mak Mar 07 '13 at 12:46
  • out of curiosity does it happen when using fopen instead of curl? – Hydra IO Mar 09 '13 at 00:29
  • @HydraIO same thing. The problem actually occured first when using a python script. – Horen Mar 09 '13 at 19:21
  • My guess is some mysql error. To verify that, we can increase the db load (keep everything else the same), and see if error rate increases. 2 quick ways: (1) insert 2 (or 3?) rows instead of 1 row to the same table for each request; (2) if you are NOT using persistent db connection, right after a db connection is established, could you let php script sleep for a hundred ms before doing anything. However,if you are using persistent connection, try to use non-persistent connections to see if the errors disappear (because persistent connection has its own problems). – Chuan Ma Mar 12 '13 at 04:58
  • Can you access the apache vhost configuration and post it (after removing any security related content)? – chris Mar 13 '13 at 08:24

4 Answers4

2

This looks pretty simple and straight forward to me. This is a 302 redirect and I can't think of anything in ZF that redirects by itself; especially not to a 500 error page. A 500 Error (internal server error) must always return a 500 error and should never ever be 302 redirect. So you are sort of lucky here because you must have some error handling in your RETS API that causes a redirect somewhere (instead of a regular error page).

Search your code for redirects. It could be done with the ZF redirector helper (inside a controller) or manually (anywhere) with header() and exit(). When you found the redirect either show (exit) with a debug_backtrace or dump that into a log file. And also fix the return code or the way the error is handled.

Adrian World
  • 3,118
  • 2
  • 16
  • 25
1

Note that when you specify an ErrorDocument that points to a remote URL (ie. anything with a method such as http in front of it), Apache will send a redirect to the client to tell it where to find the document, even if the document ends up being on the same server.

http://httpd.apache.org/docs/2.2/mod/core.html#errordocument

I assume your're using the ErrorDocument directive in your Apache HTTP server configuration that will then do as configured for 500 errors.

500 errors can be triggered by PHP itself. To find out what happens you need to take a look into both the server error log as well as into php error log (and naturally enable PHP error logging for that).

Or as I commonly write:

A 500 Internal Sever Error is always an invitation to look into the servers error log. It contains more information. As this is PHP, it's also highly likely that it is because of a Fatal Error in PHP, so ensuring that PHP error logging is enabled and looking into the PHP error log is very useful, too. More about the 500 Internal Server Error

Community
  • 1
  • 1
hakre
  • 193,403
  • 52
  • 435
  • 836
0

Without more details about your application it's quite hard to guess. My guess is one of your services (most likely a database) slows down under increased traffic and I/O. As a result it might timeout for some PHP connections. That results in a application error and redirects to the error page.

Depends on how good is your application with logging internal problems look into logs/application.log but by default it's not very good with logging things.

Lukasz Kujawa
  • 3,026
  • 1
  • 28
  • 43
  • It's possible that the MySQL database could be the bottleneck. Do you have an idea how I could prove that? – Horen Mar 07 '13 at 21:16
  • Do you know what place in the code is responsible for redirection on error? Redirection isn't a default ZF behaviour so I presume you have a custom error plugin. You have to log the error message there. Doesnt it go to logs/application.log anyway? Maybe simulate MySQL timeout and observe the behaviour? – Lukasz Kujawa Mar 07 '13 at 22:39
0

Wow - that was a totally unexpected problem and really hard to figure out...

@AdrianWorld helped me get on the right track. In the Zend ErrorController I output the error message and found the following exception:

ps_files_cleanup_dir: opendir(/var/lib/php5) failed: Permission denied (13) Array

That apparently is a pretty common problem as described and solved here.
The variable session.gc_probability was set to 1 in the php.ini which means there is a 1% probability for the garbage collector to run and clean up the directory /var/lib/php5 where the php sessions are stored. Apparently this folder is not writable by www-data resulting in the mentioned error and throwing the Zend exception.

Since session.gc_probability sets only a probability the error occured randomly making debugging pretty difficult.

Anyways, I'm happy it is solved - thanks for all the hints and guesses :)

Horen
  • 11,184
  • 11
  • 71
  • 113