Redis intermittently causing 500 Internal Error v1.5.0.8


(Keith Newton) #1

I’m currently in the process of upgrading to 1.5.0.9 to see if that resolves the issue but I’ve had problems with Redis causing 500 Internal Error in the last 2 versions of Discourse I’ve been running. Redis is being hosted on my data server with modifications to the data.yml sample whereas I have a single Discourse instance running with modifications to the web_only.yml sample (during upgrades I always check discourse_docker for latest and merge changes). I don’t use the Discourse auto-upgrade feature and instead manually do upgrades deleting all images and rebuilding everything from scratch.

The 500 Internal Server error appearance seems to coincide with the following errors in my syslog logfile on the data server:

Feb  3 13:02:46 inovaeforumsdb0-data redis[19]: Background saving started by pid 56
Feb  3 13:02:46 inovaeforumsdb0-data redis[56]: Failed opening .rdb for saving: Permission denied
Feb  3 13:02:46 inovaeforumsdb0-data redis[19]: Background saving error
Feb  3 13:02:52 inovaeforumsdb0-data redis[19]: 10 changes in 300 seconds. Saving...
Feb  3 13:02:52 inovaeforumsdb0-data redis[19]: Background saving started by pid 57
Feb  3 13:02:52 inovaeforumsdb0-data redis[57]: Failed opening .rdb for saving: Permission denied
Feb  3 13:02:52 inovaeforumsdb0-data redis[19]: Background saving error
Feb  3 13:02:58 inovaeforumsdb0-data redis[19]: 10 changes in 300 seconds. Saving...
Feb  3 13:02:58 inovaeforumsdb0-data redis[19]: Background saving started by pid 58
Feb  3 13:02:58 inovaeforumsdb0-data redis[58]: Failed opening .rdb for saving: Permission denied

If I just restart the data server everything seems to work fine anywhere from a few hours to weeks:

Feb  3 13:52:04 inovaeforumsdb0-data redis[19]: Background saving started by pid 1336
Feb  3 13:52:04 inovaeforumsdb0-data redis[1336]: Failed opening .rdb for saving: Permission denied
Feb  3 13:52:04 inovaeforumsdb0-data redis[19]: Background saving error
Feb  3 13:52:10 inovaeforumsdb0-data redis[19]: 1 changes in 900 seconds. Saving...
Feb  3 13:52:10 inovaeforumsdb0-data redis[19]: Background saving started by pid 1349
Feb  3 13:52:10 inovaeforumsdb0-data redis[1349]: Failed opening .rdb for saving: Permission denied
Feb  3 13:52:10 inovaeforumsdb0-data redis[19]: User requested shutdown...
Feb  3 13:52:10 inovaeforumsdb0-data redis[19]: There is a child saving an .rdb. Killing it!
Feb  3 13:52:10 inovaeforumsdb0-data redis[19]: Saving the final RDB snapshot before exiting.
Feb  3 13:52:10 inovaeforumsdb0-data redis[19]: Failed opening .rdb for saving: Permission denied
Feb  3 13:52:10 inovaeforumsdb0-data redis[19]: Error trying to save the DB, can't exit.
Feb  3 13:52:10 inovaeforumsdb0-data redis[19]: SIGTERM received but errors trying to shut down the server, check the logs $
Feb  3 13:52:10 inovaeforumsdb0-data redis[19]: Background saving error
Feb  3 13:52:16 inovaeforumsdb0-data redis[19]: 1 changes in 900 seconds. Saving...
Feb  3 13:52:16 inovaeforumsdb0-data redis[19]: Background saving started by pid 1358
Feb  3 13:52:16 inovaeforumsdb0-data redis[1358]: Failed opening .rdb for saving: Permission denied
Feb  3 13:52:16 inovaeforumsdb0-data redis[19]: Background saving error
Feb  3 13:52:58 inovaeforumsdb0-data rsyslogd: [origin software="rsyslogd" swVersion="7.4.4" x-pid="20" x-info="http://www.$
Feb  3 13:52:58 inovaeforumsdb0-data rsyslogd-3003: invalid or yet-unknown config file command 'KLogPermitNonKernelFacility$
Feb  3 13:52:58 inovaeforumsdb0-data rsyslogd-2307: warning: ~ action is deprecated, consider using the 'stop' statement in$
Feb  3 13:52:58 inovaeforumsdb0-data rsyslogd: rsyslogd's groupid changed to 104
Feb  3 13:52:58 inovaeforumsdb0-data rsyslogd: rsyslogd's userid changed to 101
Feb  3 13:52:58 inovaeforumsdb0-data rsyslogd-2039: Could no open output pipe '/dev/xconsole': No such file or directory [t$
Feb  3 13:52:59 inovaeforumsdb0-data redis[22]: DB loaded from disk: 1.204 seconds
Feb  3 13:52:59 inovaeforumsdb0-data redis[22]: The server is now ready to accept connections on port 6379
Feb  3 13:57:59 inovaeforumsdb0-data redis[22]: 10 changes in 300 seconds. Saving...
Feb  3 13:57:59 inovaeforumsdb0-data redis[22]: Background saving started by pid 59
Feb  3 13:57:59 inovaeforumsdb0-data redis[59]: DB saved on disk
Feb  3 13:57:59 inovaeforumsdb0-data redis[59]: RDB: 44 MB of memory used by copy-on-write
Feb  3 13:57:59 inovaeforumsdb0-data redis[22]: Background saving terminated with success
Feb  3 14:03:00 inovaeforumsdb0-data redis[22]: 10 changes in 300 seconds. Saving...
Feb  3 14:03:00 inovaeforumsdb0-data redis[22]: Background saving started by pid 67
Feb  3 14:03:00 inovaeforumsdb0-data redis[67]: DB saved on disk
Feb  3 14:03:00 inovaeforumsdb0-data redis[67]: RDB: 44 MB of memory used by copy-on-write
Feb  3 14:03:00 inovaeforumsdb0-data redis[22]: Background saving terminated with success

Anyone have any idea what could be going on? It seems like a Redis background save process is hanging and preventing all future saves from succeeding?


(Keith Newton) #2

I can confirm this problem still exists with v1.5.0.9.


(Sam Saffron) #3

Are you running low on disk space …

When is the last time you ran?

cd /var/discourse
git pull
./launcher rebuild app
./launcher cleanup

(Keith Newton) #4

About 4 hours ago I deleted all containers, all images, and rebuilt everything. I’ve discovered I’m not the only person having this problem as a thread regarding the same issue was created back in December: Losing connection with Redis

It appears the solution was to simply disable Redis persistence therefore preventing it from attempting to write the .rdb which is treating the symptom without resolving the problem. I’ll try it and see if it at least prevents my Redis from going down.


(Keith Newton) #5

Going through the Redis config I just noticed that it intentionally stops writes if background saves fail:

# By default Redis will stop accepting writes if RDB snapshots are enabled
# (at least one save point) and the latest background save failed.
# This will make the user aware (in a hard way) that data is not persisting
# on disk properly, otherwise chances are that no one will notice and some
# disaster will happen.
#
# If the background saving process will start working again Redis will
# automatically allow writes again.
#
# However if you have setup your proper monitoring of the Redis server
# and persistence, you may want to disable this feature so that Redis will
# continue to work as usual even if there are problems with disk,
# permissions, and so forth.
stop-writes-on-bgsave-error yes