rhubarbgroup / redis-cache

A persistent object cache backend for WordPress powered by Redis. Supports Predis, PhpRedis, Relay, replication, sentinels, clustering and WP-CLI.
https://wordpress.org/plugins/redis-cache/
GNU General Public License v3.0
425 stars 148 forks source link

Redis wrong message on connect/miss-connect #493

Closed NunoHiggs closed 10 months ago

NunoHiggs commented 10 months ago

When i try to connect to a Redis Cluster, i can do a tcp connection from the server, but the application is reporting connection refused. I think that it might be something else wrong with the connection configuration and not with tcp connection itself

Description

When i try to connect to a Redis Cluster, i can do a tcp connection from the server, but the application is reporting connection refused. I think that it might be something else wrong with the connection configuration and not with tcp connection itself

Expected Behavior

For it to work, the tests on the page appear green across the board:

image

But when i activate the module wordpress stops working indicating an redis error and that i should delete the module php file from the /wp-content/ dir.

Actual Behavior

Wordpress fails saying that there is something wrong with the module and if i go into the logs:

[Thu Oct 19 10:37:24.518747 2023] [php:notice] [pid 2474318] [client 172.16.0.10:55732] RedisException: Connection **refused** in /mnt/netcore/appz/blog.awsomeblog.net/wp-content/object-cache.php:728\nStack trace:\n#0

Possible Fix

I wish i knew :)

Steps to Reproduce

  1. Install plugin
  2. Add the following config to wp-settings.php
define( 'WP_REDIS_CLIENT', 'phpredis' );
define( 'WP_REDIS_CLUSTER', [
    'tcp://172.16.0.44:7000',
    'tcp://172.16.0.45:7000',
    'tcp://172.16.0.46:7000',
] );
define( 'WP_REDIS_PREFIX', 'blogblabla' );
define( 'WP_REDIS_TIMEOUT', 1 );
define( 'WP_REDIS_READ_TIMEOUT', 1 );
define( 'WP_REDIS_PASSWORD', 'XXXXXXXXXXXXX' );
  1. Enable module
  2. Crash and burn

Additional context

I was trying to increase my page speed. This prevents me on doing that

Environment

tillkruss commented 10 months ago

Are you able to connect to tcp://172.16.0.44:7000 via redis-cli from your HTTP node?

NunoHiggs commented 10 months ago

Yes i can:

# redis-cli -h 172.16.0.44 -p 7000
172.16.0.44:7000> auth XXXXXXXXXXXXXXXXXXXXXXX
OK
172.16.0.44:7000> INFO
# Server
redis_version:5.0.3
redis_git_sha1:00000000
redis_git_dirty:0
redis_build_id:7fa21edfc0646001
redis_mode:cluster
os:Linux 5.14.21-150400.24.46-default x86_64
arch_bits:64
multiplexing_api:epoll
atomicvar_api:atomic-builtin
gcc_version:8.4.1
process_id:641
run_id:2dde329604118ddc9309db0d2df8540d604734a0
tcp_port:7000
uptime_in_seconds:118980
uptime_in_days:1
hz:10
configured_hz:10
lru_clock:3343684
executable:/usr/bin/redis-server
config_file:/etc/redis/cluster/7000/redis_7000.conf

# Clients
connected_clients:8
client_recent_max_input_buffer:2
client_recent_max_output_buffer:0
blocked_clients:0
tillkruss commented 10 months ago

What happens if you create a redis.php file on your webserver and access it?

<?php

$redis = new RedisCluster(null, [
    'tcp://172.16.0.44:7000',
    'tcp://172.16.0.45:7000',
    'tcp://172.16.0.46:7000',
  ], 1.0, 1.0, false,
  'XXXXXXXXXXXXX'
);

var_dump(
  $redis->get('test')
);
NunoHiggs commented 10 months ago

Hi Tillkruss.

bool(false)

Does this mean that php is unable to connect to the server? That is so weird because i have a couple of nextcloud instances on the same server (same php, same apache, same everything) that also are using this redis cluster, albeit accessing a different DB, and they work perfectly.

Also the tcp connection from within the server also works without issue. Is there any way to understand on why this is happening?

Thanks.

tillkruss commented 10 months ago

TBH, I'm not sure. Let's ask @michael-grunder, how can we determine why RedisCluster connections fail?

michael-grunder commented 10 months ago

bool(false)

This doesn't make a whole lot of sense to me. If PhpRedis can't connect to a cluster, you would see an exception, such as this:

PHP Fatal error:  Uncaught RedisClusterException: Couldn't map cluster keyspace using any provided seed in /tmp/fuck/cluster.php:3
Stack trace:
#0 /tmp/fuck/cluster.php(3): RedisCluster->__construct()
#1 {main}
  thrown in /tmp/fuck/cluster.php on line 3

You might try adding a call to getLastError() to Till's script, to see if you get any kind of error message from the RedisCluster class, but I'm not sure you will if it's not even throwing an exception.

You could also try using the non-cluster class, to see if you can get at the server at all (both from the web server and the shell):

<?php

$redis = new Redis;
$redis->connect(ONE_OF_YOUR_HOSTS, YOUR_PORT);
$redis->auth(YOUR_PASSWORD_HERE);

var_dump($redis->info());
NunoHiggs commented 10 months ago

Hi all,

Created a new redis1.php that contains:

<?php

$redis = new Redis;
$redis->connect(172.16.0.44, 7000);
$redis->auth(XXXXXXXXXXXXXXXXXXXX);

var_dump($redis->info());

But i got this error:

[php:error] [pid 4015237] [client 172.16.0.10:53831] PHP Parse error: syntax error, unexpected floating-point number ".0", expecting ")" in redis1.php on line 4

@michael-grunder

Regarding the error you pasted, i get that error if and only if my auth password is wrong:

Wrong password:

PHP Fatal error:  Uncaught RedisClusterException: Couldn't map cluster keyspace using any provided seed in /mnt/cloud/prod/nextcloud/redis.php:3
Stack trace:
#0 /mnt/cloud/prod/nextcloud/redis.php(3): RedisCluster->__construct()
#1 {main}
  thrown in redis.php on line 3

Right password:

php redis.php 
bool(false)
tillkruss commented 10 months ago

Try this:

<?php

$redis = new Redis;
-$redis->connect(172.16.0.44, 7000);
+$redis->connect('172.16.0.44', 7000);
$redis->auth(XXXXXXXXXXXXXXXXXXXX);

var_dump($redis->info());
michael-grunder commented 10 months ago

Yes, please try @tillkruss's change. In addition to that, I just realized that bool(false) is the correct return if a key doesn't exist, so there may not be a bug here.

<?php

$seeds = [
    'tcp://172.16.0.44:7000',
    'tcp://172.16.0.45:7000',
    'tcp://172.16.0.46:7000',
];

// *** NOTE: Change this to your password ***
$password = 'XXXXXXXXXXXXX';

$seeds = ['127.0.0.1:7000'];
$password = 'secret';

$redis = new RedisCluster(null, $seeds, 1.0, 1.0, false, $password);

$kvals = [
    'key1' => uniqid(),
    'key2' => uniqid(),
    'key3' => uniqid()
];

foreach ($kvals as $key => $val) {
    $res = $redis->set($key, $val);
    printf("SET '%s' => '%s': %s\n", $key, $val, $res ? 'OK' : 'ERR');
}

foreach ($kvals as $key => $val) {
    $res = $redis->get($key);
    printf("GET '%s' => '%s': %s\n", $key, $res, $res === $val ? 'OK' : 'ERR');
}

printf("--- Getting all the keys at once ---\n");
var_dump($redis->mget(array_keys($kvals)));
NunoHiggs commented 10 months ago

@tillkruss,

We got a hit:

array(130) {
  ["redis_version"]=>
  string(5) "5.0.3"
  ["redis_git_sha1"]=>
  int(0)
  ["redis_git_dirty"]=>
  int(0)
  ["redis_build_id"]=>
  string(16) "7fa21edfc0646001"
  ["redis_mode"]=>
  string(7) "cluster"
  ["os"]=>
  string(41) "Linux 5.14.21-150400.24.46-default x86_64"
  ["arch_bits"]=>
  int(64)
  ["multiplexing_api"]=>
  string(5) "epoll"
  ["atomicvar_api"]=>
  string(14) "atomic-builtin"
  ["gcc_version"]=>
  string(5) "8.4.1"
  ["process_id"]=>
  int(641)
  ["run_id"]=>
  string(40) "2dde329604118ddc9309db0d2df8540d604734a0"
  ["tcp_port"]=>
  int(7000)
  ["uptime_in_seconds"]=>
  int(457022)
  ["uptime_in_days"]=>
  int(5)
  ["hz"]=>
  int(10)
  ["configured_hz"]=>
  int(10)
  ["lru_clock"]=>
  int(3681726)
  ["executable"]=>
  string(21) "/usr/bin/redis-server"
  ["config_file"]=>
  string(39) "/etc/redis/cluster/7000/redis_7000.conf"
  ["connected_clients"]=>
  int(8)
  ["client_recent_max_input_buffer"]=>
  int(2)
  ["client_recent_max_output_buffer"]=>
  int(0)
  ["blocked_clients"]=>
  int(0)
  ["used_memory"]=>
  int(3621736)
  ["used_memory_human"]=>
  string(5) "3.45M"
  ["used_memory_rss"]=>
  int(6356992)
  ["used_memory_rss_human"]=>
  string(5) "6.06M"
  ["used_memory_peak"]=>
  int(3846872)
  ["used_memory_peak_human"]=>
  string(5) "3.67M"
  ["used_memory_peak_perc"]=>
  string(6) "94.15%"
  ["used_memory_overhead"]=>
  int(2739092)
  ["used_memory_startup"]=>
  int(1462816)
  ["used_memory_dataset"]=>
  int(882644)
  ["used_memory_dataset_perc"]=>
  string(6) "40.88%"
  ["allocator_allocated"]=>
  int(3687224)
  ["allocator_active"]=>
  int(4059136)
  ["allocator_resident"]=>
  int(6782976)
  ["total_system_memory"]=>
  int(16217841664)
  ["total_system_memory_human"]=>
  string(6) "15.10G"
  ["used_memory_lua"]=>
  int(37888)
  ["used_memory_lua_human"]=>
  string(6) "37.00K"
  ["used_memory_scripts"]=>
  int(0)
  ["used_memory_scripts_human"]=>
  string(2) "0B"
  ["number_of_cached_scripts"]=>
  int(0)
  ["maxmemory"]=>
  int(0)
  ["maxmemory_human"]=>
  string(2) "0B"
  ["maxmemory_policy"]=>
  string(10) "noeviction"
  ["allocator_frag_ratio"]=>
  float(1.1)
  ["allocator_frag_bytes"]=>
  int(371912)
  ["allocator_rss_ratio"]=>
  float(1.67)
  ["allocator_rss_bytes"]=>
  int(2723840)
  ["rss_overhead_ratio"]=>
  float(0.94)
  ["rss_overhead_bytes"]=>
  int(-425984)
  ["mem_fragmentation_ratio"]=>
  float(1.79)
  ["mem_fragmentation_bytes"]=>
  int(2798408)
  ["mem_not_counted_for_evict"]=>
  int(0)
  ["mem_replication_backlog"]=>
  int(1048576)
  ["mem_clients_slaves"]=>
  int(0)
  ["mem_clients_normal"]=>
  int(168148)
  ["mem_aof_buffer"]=>
  int(0)
  ["mem_allocator"]=>
  string(14) "jemalloc-5.1.0"
  ["active_defrag_running"]=>
  int(0)
  ["lazyfree_pending_objects"]=>
  int(0)
  ["loading"]=>
  int(0)
  ["rdb_changes_since_last_save"]=>
  int(126161)
  ["rdb_bgsave_in_progress"]=>
  int(0)
  ["rdb_last_save_time"]=>
  int(1697723520)
  ["rdb_last_bgsave_status"]=>
  string(2) "ok"
  ["rdb_last_bgsave_time_sec"]=>
  int(-1)
  ["rdb_current_bgsave_time_sec"]=>
  int(-1)
  ["rdb_last_cow_size"]=>
  int(0)
  ["aof_enabled"]=>
  int(0)
  ["aof_rewrite_in_progress"]=>
  int(0)
  ["aof_rewrite_scheduled"]=>
  int(0)
  ["aof_last_rewrite_time_sec"]=>
  int(-1)
  ["aof_current_rewrite_time_sec"]=>
  int(-1)
  ["aof_last_bgrewrite_status"]=>
  string(2) "ok"
  ["aof_last_write_status"]=>
  string(2) "ok"
  ["aof_last_cow_size"]=>
  int(0)
  ["total_connections_received"]=>
  int(27057)
  ["total_commands_processed"]=>
  int(520537)
  ["instantaneous_ops_per_sec"]=>
  int(0)
  ["total_net_input_bytes"]=>
  int(83536352)
  ["total_net_output_bytes"]=>
  int(74382912)
  ["instantaneous_input_kbps"]=>
  float(0)
  ["instantaneous_output_kbps"]=>
  float(0.05)
  ["rejected_connections"]=>
  int(0)
  ["sync_full"]=>
  int(0)
  ["sync_partial_ok"]=>
  int(0)
  ["sync_partial_err"]=>
  int(0)
  ["expired_keys"]=>
  int(0)
  ["expired_stale_perc"]=>
  float(0)
  ["expired_time_cap_reached_count"]=>
  int(0)
  ["evicted_keys"]=>
  int(0)
  ["keyspace_hits"]=>
  int(0)
  ["keyspace_misses"]=>
  int(0)
  ["pubsub_channels"]=>
  int(0)
  ["pubsub_patterns"]=>
  int(0)
  ["latest_fork_usec"]=>
  int(0)
  ["migrate_cached_sockets"]=>
  int(0)
  ["slave_expires_tracked_keys"]=>
  int(0)
  ["active_defrag_hits"]=>
  int(0)
  ["active_defrag_misses"]=>
  int(0)
  ["active_defrag_key_hits"]=>
  int(0)
  ["active_defrag_key_misses"]=>
  int(0)
  ["role"]=>
  string(5) "slave"
  ["master_host"]=>
  string(11) "172.16.0.46"
  ["master_port"]=>
  int(7001)
  ["master_link_status"]=>
  string(2) "up"
  ["master_last_io_seconds_ago"]=>
  int(3)
  ["master_sync_in_progress"]=>
  int(0)
  ["slave_repl_offset"]=>
  int(407210391)
  ["slave_priority"]=>
  int(100)
  ["slave_read_only"]=>
  int(1)
  ["connected_slaves"]=>
  int(0)
  ["master_replid"]=>
  string(40) "ac0ad3c206473ad50fe4eb7f72b8fdf6b09d73f9"
  ["master_replid2"]=>
  int(0)
  ["master_repl_offset"]=>
  int(407210391)
  ["second_repl_offset"]=>
  int(-1)
  ["repl_backlog_active"]=>
  int(1)
  ["repl_backlog_size"]=>
  int(1048576)
  ["repl_backlog_first_byte_offset"]=>
  int(406161816)
  ["repl_backlog_histlen"]=>
  int(1048576)
  ["used_cpu_sys"]=>
  float(537.568154)
  ["used_cpu_user"]=>
  float(468.484845)
  ["used_cpu_sys_children"]=>
  float(0)
  ["used_cpu_user_children"]=>
  float(0)
  ["cluster_enabled"]=>
  int(1)
  ["db0"]=>
  string(37) "keys=805,expires=457,avg_ttl=15458050"
}
NunoHiggs commented 10 months ago

@michael-grunder what does this part of the code refers to?

$seeds = ['127.0.0.1:7000'];
$password = 'secret';

I dont have any redis running on this server. I replaced it with one of my redis servers:

<?php

$seeds = [
    'tcp://172.16.0.44:7000',
    'tcp://172.16.0.45:7000',
    'tcp://172.16.0.46:7000',
];

$password = 'XXXXXXXX';

$seeds = ['172.16.0.45:7000'];
$password = 'XXXXXXXX';

$redis = new RedisCluster(null, $seeds, 1.0, 1.0, false, $password);

$kvals = [
    'key1' => uniqid(),
    'key2' => uniqid(),
    'key3' => uniqid()
];

foreach ($kvals as $key => $val) {
    $res = $redis->set($key, $val);
    printf("SET '%s' => '%s': %s\n", $key, $val, $res ? 'OK' : 'ERR');
}

foreach ($kvals as $key => $val) {
    $res = $redis->get($key);
    printf("GET '%s' => '%s': %s\n", $key, $res, $res === $val ? 'OK' : 'ERR');
}

printf("--- Getting all the keys at once ---\n");
var_dump($redis->mget(array_keys($kvals)));

As a result we now have:

# php redis.php 
SET 'key1' => '65382ee7dbd1d': OK
SET 'key2' => '65382ee7dbd28': OK
SET 'key3' => '65382ee7dbd29': OK
GET 'key1' => '65382ee7dbd1d': OK
GET 'key2' => '65382ee7dbd28': OK
GET 'key3' => '65382ee7dbd29': OK
--- Getting all the keys at once ---
array(3) {
  [0]=>
  string(13) "65382ee7dbd1d"
  [1]=>
  string(13) "65382ee7dbd28"
  [2]=>
  string(13) "65382ee7dbd29"
}

For a moment i thought i might have forgotten a ' in the configuration but not is the case:

define( 'WP_REDIS_CLIENT', 'phpredis' );
define( 'WP_REDIS_CLUSTER', [
    'tcp://172.16.0.44:7000',
    'tcp://172.16.0.45:7000',
    'tcp://172.16.0.46:7000',
] );
define( 'WP_REDIS_PREFIX', 'awsomeblog' );
define( 'WP_REDIS_TIMEOUT', 1 );
define( 'WP_REDIS_READ_TIMEOUT', 1 );
define( 'WP_REDIS_PASSWORD', 'XXXXXXXXXXXXXXXX' );
michael-grunder commented 10 months ago

Apologies, I didn't remove the local debug values for seeds that I was using to test the script.

From the output you're getting PhpRedis is able to connect just fine. The only difference I see is that in your WP_REDIS_CONFIG the values are prefixed with tcp://. I don't think that should matter, but worth removing I suppose.

NunoHiggs commented 10 months ago

@michael-grunder i removed the tcp string from the configuration and the error remains:

Config:

define( 'WP_REDIS_CLIENT', 'phpredis' );
define( 'WP_REDIS_CLUSTER', [
    '172.16.0.44:7000',
    '172.16.0.45:7000',
    '172.16.0.46:7000',
] );
define( 'WP_REDIS_PREFIX', 'blognuneshiggscom' );
define( 'WP_REDIS_TIMEOUT', 1 );
define( 'WP_REDIS_READ_TIMEOUT', 1 );
define( 'WP_REDIS_PASSWORD', 'XXXXXXXXXXXXXXXXXXXXX' )

Log:

 RedisException: Connection refused in /mnt/netcore/appz/awsomeblog.net/wp-content/object-cache.php:728\nStack trace:\n#0 /mnt/netcore/appz/awsomeblog.net/wp-content/object-cache.php(728): Redis->connect()\n#1 /mnt/netcore/appz/awsomeblog.net/wp-content/object-cache.php(540): WP_Object_Cache->connect_using_phpredis()\n#2 /mnt/netcore/appz/awsomeblog.net/wp-content/object-cache.php(256): WP_Object_Cache->__construct()\n#3 /mnt/netcore/appz/awsomeblog.net/wp-includes/load.php(851): wp_cache_init()\n#4 /mnt/netcore/appz/awsomeblog.net/wp-settings.php(131): wp_start_object_cache()\n#5 /mnt/netcore/appz/awsomeblog.net/wp-config.php(75): require_once('...')\n#6 /mnt/netcore/appz/awsomeblog.net/wp-load.php(50): require_once('...')\n#7 /mnt/netcore/appz/awsomeblog.net/wp-admin/admin.php(34): require_once('...')\n#8 /mnt/netcore/appz/
Oct 25 07:18:56 cvpar2 cluster_httpd_blog.nuneshiggs.co awsomeblog.net/wp-admin/options-general.php(10): require_once('...')\n#9 {main}, referer: https://awsomeblog.net/wp-admin/options-general.php?page=redis-cache

However, as before, the diagnosis page on the plugin itself shows everything as green:

image

michael-grunder commented 10 months ago

From the callstack, the exception is happening on this line.

https://github.com/rhubarbgroup/redis-cache/blob/4c5610eab110790613ce47e24160da272b91fce3/includes/object-cache.php#L728

This is relevant, because it's trying to connect to a non-cluster instance via Redis->connect.

#0 /mnt/netcore/appz/awsomeblog.net/wp-content/object-cache.php(728): Redis->connect()

From the first issue in the thread, you said you were defining this in wp-settings.php:

define( 'WP_REDIS_CLUSTER', [
    'tcp://172.16.0.44:7000',
    'tcp://172.16.0.45:7000',
    'tcp://172.16.0.46:7000',
] );

The define seems OK, but I think you want to place it in wp-config.php as wp-settings.php is not supposed to be edited.

Scanning through the logic of connect_using_phpredis it looks like you'd hit line 728 if none of the relevant constants are defined. Try placing a debug statement above the following line

https://github.com/rhubarbgroup/redis-cache/blob/4c5610eab110790613ce47e24160da272b91fce3/includes/object-cache.php#L674

Just dump the values for the defines like so:

var_dump([WP_REDIS_CLUSTER, WP_REDIS_CLIENT]);

I think what's likely happening is that there is no define, so it's never getting to the cluster logic.

NunoHiggs commented 10 months ago

@michael-grunder

Thanks so much for your quick reply.

I moved the configuration to the bottom of wp-config.php and added the code you indicated and it appears that you are right. The variable is not being defined:


Oct 25 17:08:57 cvpar2 cluster_httpd_awsomeblog.net [Wed Oct 25 17:08:57.445480 2023] [php:error] [pid 353148] [client 172.16.0.10:61664] PHP Fatal error:  Uncaught Error: Undefined constant "WP_REDIS_CLUSTER" in /mnt/netcore/appz/awsomeblog.net/wp-content/object-awsomeblog.net.php:673\nStack trace:\n#0 /mnt/netcore/appz/awsomeblog.net/wp-content/object-awsomeblog.net.php(540): WP_Object_awsomeblog.net->connect_using_phpredis()\n#1 /mnt/netcore/appz/awsomeblog.net/wp-content/object-awsomeblog.net.php(256): WP_Object_awsomeblog.net->__construct()\n#2 /mnt/netcore/appz/awsomeblog.net/wp-includes/load.php(851): wp_awsomeblog.net_init()\n#3 /mnt/netcore/appz/awsomeblog.net/wp-settings.php(131): wp_start_object_awsomeblog.net()\n#4 /mnt/netcore/appz/awsomeblog.net/wp-config.php(75): require_once('...')\n#5 /mnt/netcore/appz/awsomeblog.net/wp-load.php(50): require_once('...')\n#6 /mnt/netcore/appz/awsomeblog.net/wp-admin/admin.php(34): require_once('...')\n#7 /mnt/netcore/appz/awsomeblog.net/wp-admin/options-general.php(10): req
Oct 25 17:08:57 cvpar2 cluster_httpd_blog.nuneshiggs.co uire_once('...')\n#8 {main}\n  thrown in /mnt/netcore/appz/awsomeblog.net/wp-content/object-awsomeblog.net.php on line 673, referer: https://awsomeblog.net/wp-admin/options-general.php?page=redis-awsomeblog.net

I re-read the configuration how to and found that my issue was that i had defined my configuration AFTER this line

require_once(ABSPATH . 'wp-settings.php');

I set the line to the bottom and it worked perfectly.

Thanks so much for all your effort.