Redis spontaneously failed: “Failed opening .rdb for saving: Permission denied”

redisubuntu-14.04

I am running redis-server (ver. 2.8.4) on Ubuntu 14.04 in Rackspace Cloud Server. The redis-server process is being run by the redis user.

Early this morning, the Redis server spontaneously began failing "opening .rdb for saving." This occurred after the process had been up for over 20 days without incident.

As you can see in the snippet from the logs below, Redis was behaving normally, and then started failing around at 8:08am UTC. Power-cycling the server later resolved the issue.

[26083] 31 Aug 07:54:47.089 * RDB: 2 MB of memory used by copy-on-write
[17183] 31 Aug 07:54:47.186 * Background saving terminated with success
[17183] 31 Aug 07:59:48.028 * 10 changes in 300 seconds. Saving...
[17183] 31 Aug 07:59:48.029 * Background saving started by pid 26653
[26653] 31 Aug 07:59:48.032 * DB saved on disk
[26653] 31 Aug 07:59:48.032 * RDB: 2 MB of memory used by copy-on-write
[17183] 31 Aug 07:59:48.129 * Background saving terminated with success
[17183] 31 Aug 08:04:49.061 * 10 changes in 300 seconds. Saving...
[17183] 31 Aug 08:04:49.061 * Background saving started by pid 27197
[27197] 31 Aug 08:04:49.064 * DB saved on disk
[27197] 31 Aug 08:04:49.065 * RDB: 2 MB of memory used by copy-on-write
[17183] 31 Aug 08:04:49.162 * Background saving terminated with success
[17183] 31 Aug 08:07:56.881 * DB saved on disk
[17183] 31 Aug 08:08:05.880 # Failed opening .rdb for saving: Permission denied
[17183] 31 Aug 08:12:57.047 * 10 changes in 300 seconds. Saving...
[17183] 31 Aug 08:12:57.047 * Background saving started by pid 28087
[28087] 31 Aug 08:12:57.048 # Failed opening .rdb for saving: Permission denied
[17183] 31 Aug 08:12:57.148 # Background saving error
[17183] 31 Aug 08:13:03.068 * 10 changes in 300 seconds. Saving...
[17183] 31 Aug 08:13:03.069 * Background saving started by pid 28088
[28088] 31 Aug 08:13:03.070 # Failed opening .rdb for saving: Permission denied
[17183] 31 Aug 08:13:03.169 # Background saving error
[17183] 31 Aug 08:13:09.087 * 10 changes in 300 seconds. Saving...
[17183] 31 Aug 08:13:09.087 * Background saving started by pid 28089
[28089] 31 Aug 08:13:09.088 # Failed opening .rdb for saving: Permission denied
(... continues like this until server restart)

So, my question: how could this happen?

I'm stumped, but here are my vague hunches:

  • Memory use too high (I am running just a 512MB instance and Redis has warned me to set 'vm.overcommit_memory = 1' in /etc/sysctl.conf)
  • Redis hit some kind of internal limit after 20 days of continual operation (and so this will happen again in another ~20 days).
  • Rackspace did something at 8am UTC (4am Eastern time) that somehow impacted my server.

Best Answer

Run redis-cli and look at the output for CONFIG GET dbfilename and CONFIG GET dir

I have a feeling those may have been changed. Values should be dump.rdb and something like /var/lib/redis, respectively.

If they have changed, someone compromised your redis server. If that's the case, check to see if your redis service is open to the public. You shouldn't be able to connect to it from an external IP.