Redis PhpRedis Stack Trace #168

Closed
kyleamadio opened this Issue Apr 18, 2012 · 2 comments

Comments

Projects
None yet
1 participant
@kyleamadio

I have been testing phpredis for performance and stability reasons. Performance is excellent , however I am seeing a repeatable stack trace error after sustained testing - running the same script via 'ab'.

Pattern is run this test 3 to 4 times

ab -n 10000 -c 10 -k "http://localhost:84/index.php?rw_app_id=1&code=test&device_id=test"

(If I run the request from a browser I cannot seem to get the error to appear, although that may because I cannot load the processes up.)

usually during the 3rd or 4th iteration the Apache error log reports the following:

Apache Error Log:

[warn] [client 127.0.0.1] mod_fcgid: stderr: PHP Fatal error: Uncaught exception 'RedisException' with message 'Redis server went away' in /var/www/web1/web/index.php:108

[warn] [client 127.0.0.1] mod_fcgid: stderr: Stack trace: [Wed Apr 18 16:39:49 2012] [warn] [client 127.0.0.1] mod_fcgid: stderr: #0 /var/www/web1/web/index.php(108): Redis->hGet('rw_promo_code:1...', 'unlock_code')

[warn] [client 127.0.0.1] mod_fcgid: stderr: #1 /var/www/web1/web/index.php(172): RedeemAPI->redeem()

[warn] [client 127.0.0.1] mod_fcgid: stderr: #2 {main}

[warn] [client 127.0.0.1] mod_fcgid: stderr: Next exception 'RedisException' with message 'Redis server went away' in /var/www/web1/web/index.php:0

[warn] [client 127.0.0.1] mod_fcgid: stderr: Stack trace:

[warn] [client 127.0.0.1] mod_fcgid: stderr: #0 /var/www/web1/web/index.php(172): Redis->__destruct()

[warn] [client 127.0.0.1] mod_fcgid: stderr: #1 /var/www/web1/web/index.php(172): RedeemAPI->redeem()

[warn] [client 127.0.0.1] mod_fcgid: stderr: #2 {main}

[warn] [client 127.0.0.1] mod_fcgid: stderr: thrown in /var/www/web1/web/index.php on line 0

[warn] [client 127.0.0.1] mod_fcgid: stderr: PHP Fatal error: Uncaught exception 'RedisException' with message 'Redis server went away' in /var/www/web1/web/index.php:108

[warn] [client 127.0.0.1] mod_fcgid: stderr: Stack trace:

[warn] [client 127.0.0.1] mod_fcgid: stderr: #0 /var/www/web1/web/index.php(108): Redis->hGet('rw_promo_code:1...', 'unlock_code')

[warn] [client 127.0.0.1] mod_fcgid: stderr: #1 /var/www/web1/web/index.php(172): RedeemAPI->redeem()

[warn] [client 127.0.0.1] mod_fcgid: stderr: #2 {main}

[warn] [client 127.0.0.1] mod_fcgid: stderr: Next exception 'RedisException' with message 'Redis server went away' in /var/www/web1/web/index.php:0

[warn] [client 127.0.0.1] mod_fcgid: stderr: Stack trace:

[warn] [client 127.0.0.1] mod_fcgid: stderr: #0 /var/www/web1/web/index.php(172): Redis->__destruct()

[warn] [client 127.0.0.1] mod_fcgid: stderr: #1 /var/www/web1/web/index.php(172): RedeemAPI->redeem()

[warn] [client 127.0.0.1] mod_fcgid: stderr: #2 {main}

[warn] [client 127.0.0.1] mod_fcgid: stderr: thrown in /var/www/web1/web/index.php on line 0

[warn] [client 127.0.0.1] mod_fcgid: stderr: PHP Fatal error: Uncaught exception 'RedisException' with message 'Redis server went away' in /var/www/web1/web/index.php:108

etc....

Restart Apache and Redis and can repeat the cycle. Occasionally it will connect again and process some requests successfully.

I can try catch the exception and try a reconnect however the processes does not recover.

Ubuntu x86_64 11.10 Redis Version 2.4 Apache/2.2.20 (Ubuntu) mod_fastcgi/mod_fastcgi-SNAP-0910052141 mod_fcgid/2.3.6 mod_perl/2.0.5 Perl/v5.12.4

Apologies - this was also posted at stackoverflow.com

@kyleamadio

This comment has been minimized.

Show comment Hide comment
@kyleamadio

kyleamadio Apr 18, 2012

If I run

redis-benchmark -t get -n 1000000 -r 100000000 -c 50 -d 4096

at the same time as the errors are appearing in the Apache error log this error is reported by redis-benchmark

Could not connect to Redis at 127.0.0.1:6379: Cannot assign requested address

Maybe its a socket blocking problem - the PHPRedis script opens and closes the connection for each request - wonder if the benchmark tool just opens a socket and does its business?

If I run

redis-benchmark -t get -n 1000000 -r 100000000 -c 50 -d 4096

at the same time as the errors are appearing in the Apache error log this error is reported by redis-benchmark

Could not connect to Redis at 127.0.0.1:6379: Cannot assign requested address

Maybe its a socket blocking problem - the PHPRedis script opens and closes the connection for each request - wonder if the benchmark tool just opens a socket and does its business?

@kyleamadio

This comment has been minimized.

Show comment Hide comment
@kyleamadio

kyleamadio Apr 19, 2012

Found this antirez/redis#340:

This is likely caused by the OS not cleaning up connections fast enough. The following warning is issued when keepalive is disabled for redis-benchmark, but holds just as well for running a looping benchmark:

WARNING: keepalive disabled, you probably need

echo 1 > /proc/sys/net/ipv4/tcp_tw_reuse for Linux and

sudo sysctl -w net.inet.tcp.msl=1000 for Mac OS X in order to use a lot of clients/requests

I tested this and it helped - however I still get so errors

[warn] client 127.0.0.1Connection reset by peer: mod_fcgid: error reading data from FastCGI server [error] [client 127.0.0.1] Premature end of script headers: index.php

Update:

Have tested 1,000,000 requests - 10 at a time - with zero errors.

Found this antirez/redis#340:

This is likely caused by the OS not cleaning up connections fast enough. The following warning is issued when keepalive is disabled for redis-benchmark, but holds just as well for running a looping benchmark:

WARNING: keepalive disabled, you probably need

echo 1 > /proc/sys/net/ipv4/tcp_tw_reuse for Linux and

sudo sysctl -w net.inet.tcp.msl=1000 for Mac OS X in order to use a lot of clients/requests

I tested this and it helped - however I still get so errors

[warn] client 127.0.0.1Connection reset by peer: mod_fcgid: error reading data from FastCGI server [error] [client 127.0.0.1] Premature end of script headers: index.php

Update:

Have tested 1,000,000 requests - 10 at a time - with zero errors.

@kyleamadio kyleamadio closed this Apr 19, 2012

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment