Used the default configuration of using snapshotting and no AOF:
save 900 1
save 300 10
save 60 10000
In fact redis.conf was exactly identical to the one that comes with Redis in my version of Debian (I have verified this).
I had been running redis for almost a month (last time it restarted was due to a power outage), adding and modifying keys now and then. Today I wanted to enable AOF, so I changed from appendonly no to appendonly yes i redis.conf and did a systemctl restart redis. After that I got curious on how the old snapshot configuration I have actually works in practice so I created a few test keys using redis-cli while repeatedly doing ls -l /var/lib/redis to see when the snapshot would be saved. As expected, as soon as I had created 10 keys and 5 minutes had passed, the size and mtime of dump.rdb changed. Then I got curious on how many keys I actually have in total so I did a keys *. Slightly shocked to discover that the only existing keys was the 10 test keys I had just created. Fortunately I had less than 100 keys or so and the important ones can be recreated manually.
Two things worth mentioning:
While I did the ls -l thing, I noticed dump.rdb decreased in size when it was written. To me it seems like it actually had my old keys in it at first but then got overwritten as soon as the first save was done (the original size seems to be roughly consistent with how many keys I had):
root@x:~# ls /var/lib/redis/
dump.rdb
root@x:~# nano -w /etc/redis/redis.conf
root@x:~# systemctl restart redis
root@x:~# ls /var/lib/redis/
appendonly.aof dump.rdb
root@x:~# ls -l /var/lib/redis/
totalt 32
-rw-r----- 1 redis redis 0 14 nov 10.19 appendonly.aof
-rw-rw---- 1 redis redis 30513 14 nov 10.19 dump.rdb
root@x:~# ls -l /var/lib/redis/
totalt 36
-rw-r----- 1 redis redis 53 14 nov 10.20 appendonly.aof
-rw-rw---- 1 redis redis 30513 14 nov 10.19 dump.rdb
root@x:~# ls -l /var/lib/redis/
totalt 36
-rw-r----- 1 redis redis 53 14 nov 10.20 appendonly.aof
-rw-rw---- 1 redis redis 30513 14 nov 10.19 dump.rdb
root@x:~# ls -l /var/lib/redis/
totalt 36
-rw-r----- 1 redis redis 115 14 nov 10.21 appendonly.aof
-rw-rw---- 1 redis redis 30513 14 nov 10.19 dump.rdb
root@x:~# ls -l /var/lib/redis/
totalt 36
-rw-r----- 1 redis redis 115 14 nov 10.21 appendonly.aof
-rw-rw---- 1 redis redis 30513 14 nov 10.19 dump.rdb
root@x:~# ls -l /var/lib/redis/
totalt 8
-rw-r----- 1 redis redis 365 14 nov 10.25 appendonly.aof
-rw-rw---- 1 redis redis 188 14 nov 10.25 dump.rdb
root@x:~# ls -l /var/lib/redis/
totalt 8
-rw-r----- 1 redis redis 365 14 nov 10.25 appendonly.aof
-rw-rw---- 1 redis redis 188 14 nov 10.25 dump.rdb
(I restarted Redis at 10:19am so that is consistent with Redis saving dump.rdb at shutdown as expected.)
The other thing is a few hours before I restarted Redis I got a "redis.exceptions.ResponseError: Background save already in progress" exception in the Python application that is more or less the sole user of Redis. It originated in this code which is new:
p = r.pipeline()
p.SREM('x:to-process', found)
p.SADD('x:processing', id_)
p.execute()
r.save()
The idea of the immediate save is to be sure we can detect potentially "half processed" items after a power loss, which is crucial for what I'm doing. Presumably the reason for the error was that the srem and sadd triggered a background save which was still running. Just thought I should mention it.
redis-server.log:
835:M 07 Nov 2023 12:05:10.404 * 1 changes in 900 seconds. Saving...
835:M 07 Nov 2023 12:05:10.405 * Background saving started by pid 217274
217274:C 07 Nov 2023 12:05:10.458 * DB saved on disk
217274:C 07 Nov 2023 12:05:10.459 * RDB: 0 MB of memory used by copy-on-write
835:M 07 Nov 2023 12:05:10.505 * Background saving terminated with success
835:M 07 Nov 2023 12:24:11.009 * 1 changes in 900 seconds. Saving...
835:M 07 Nov 2023 12:24:11.009 * Background saving started by pid 217335
217335:C 07 Nov 2023 12:24:11.058 * DB saved on disk
217335:C 07 Nov 2023 12:24:11.060 * RDB: 0 MB of memory used by copy-on-write
835:M 07 Nov 2023 12:24:11.110 * Background saving terminated with success
835:M 14 Nov 2023 06:50:21.147 * 1 changes in 900 seconds. Saving...
835:M 14 Nov 2023 06:50:21.177 * Background saving started by pid 267982
267982:C 14 Nov 2023 06:50:21.304 * DB saved on disk
267982:C 14 Nov 2023 06:50:21.306 * RDB: 0 MB of memory used by copy-on-write
835:M 14 Nov 2023 06:50:21.377 * Background saving terminated with success
835:M 14 Nov 2023 08:05:22.081 * 1 changes in 900 seconds. Saving...
835:M 14 Nov 2023 08:05:22.082 * Background saving started by pid 268074
268074:C 14 Nov 2023 08:05:22.131 * DB saved on disk
268074:C 14 Nov 2023 08:05:22.133 * RDB: 0 MB of memory used by copy-on-write
835:M 14 Nov 2023 08:05:22.182 * Background saving terminated with success
835:signal-handler (1699953597) Received SIGTERM scheduling shutdown...
835:M 14 Nov 2023 10:19:57.167 # User requested shutdown...
835:M 14 Nov 2023 10:19:57.167 * Saving the final RDB snapshot before exiting.
835:M 14 Nov 2023 10:19:57.275 * DB saved on disk
835:M 14 Nov 2023 10:19:57.275 * Removing the pid file.
835:M 14 Nov 2023 10:19:57.275 # Redis is now ready to exit, bye bye...
268498:C 14 Nov 2023 10:19:57.691 # WARNING supervised by systemd - you MUST set appropriate values for TimeoutStartSec and TimeoutStopSec in your service unit.
268498:C 14 Nov 2023 10:19:57.691 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
268498:C 14 Nov 2023 10:19:57.691 # Redis version=6.0.16, bits=64, commit=00000000, modified=0, pid=268498, just started
268498:C 14 Nov 2023 10:19:57.691 # Configuration loaded
_._
_.-``__ ''-._
_.-`` `. `_. ''-._ Redis 6.0.16 (00000000/0) 64 bit
.-`` .-```. ```\/ _.,_ ''-._
( ' , .-` | `, ) Running in standalone mode
|`-._`-...-` __...-.``-._|'` _.-'| Port: 6379
| `-._ `._ / _.-' | PID: 268498
`-._ `-._ `-./ _.-' _.-'
|`-._`-._ `-.__.-' _.-'_.-'|
| `-._`-._ _.-'_.-' | http://redis.io
`-._ `-._`-.__.-'_.-' _.-'
|`-._`-._ `-.__.-' _.-'_.-'|
| `-._`-._ _.-'_.-' |
`-._ `-._`-.__.-'_.-' _.-'
`-._ `-.__.-' _.-'
`-._ _.-'
`-.__.-'
268498:M 14 Nov 2023 10:19:57.693 # Server initialized
268498:M 14 Nov 2023 10:19:57.693 # WARNING overcommit_memory is set to 0! Background save may fail under low memory condition. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.
268498:M 14 Nov 2023 10:19:57.693 # WARNING you have Transparent Huge Pages (THP) support enabled in your kernel. This will create latency and memory usage issues with Redis. To fix this issue run the command 'echo madvise > /sys/kernel/mm/transparent_hugepage/enabled' as root, and add it to your /etc/rc.local in order to retain the setting after a reboot. Redis must be restarted after THP is disabled (set to 'madvise' or 'never').
268498:M 14 Nov 2023 10:19:57.693 * Ready to accept connections
268498:M 14 Nov 2023 10:25:20.819 * 10 changes in 300 seconds. Saving...
268498:M 14 Nov 2023 10:25:20.860 * Background saving started by pid 268562
268562:C 14 Nov 2023 10:25:20.906 * DB saved on disk
268562:C 14 Nov 2023 10:25:20.907 * RDB: 0 MB of memory used by copy-on-write
268498:M 14 Nov 2023 10:25:20.960 * Background saving terminated with success
268498:M 14 Nov 2023 10:40:21.036 * 1 changes in 900 seconds. Saving...
268498:M 14 Nov 2023 10:40:21.036 * Background saving started by pid 268639
268639:C 14 Nov 2023 10:40:21.074 * DB saved on disk
268639:C 14 Nov 2023 10:40:21.075 * RDB: 0 MB of memory used by copy-on-write
268498:M 14 Nov 2023 10:40:21.137 * Background saving terminated with success
redis-server.service (not modified by me):
# /lib/systemd/system/redis-server.service
[Unit]
Description=Advanced key-value store
After=network.target
Documentation=http://redis.io/documentation, man:redis-server(1)
[Service]
Type=notify
ExecStart=/usr/bin/redis-server /etc/redis/redis.conf --supervised systemd --daemonize no
PIDFile=/run/redis/redis-server.pid
TimeoutStopSec=0
Restart=always
User=redis
Group=redis
RuntimeDirectory=redis
RuntimeDirectoryMode=2755
UMask=007
PrivateTmp=yes
LimitNOFILE=65535
PrivateDevices=yes
ProtectHome=yes
ReadOnlyDirectories=/
ReadWritePaths=-/var/lib/redis
ReadWritePaths=-/var/log/redis
ReadWritePaths=-/var/run/redis
NoNewPrivileges=true
CapabilityBoundingSet=CAP_SETGID CAP_SETUID CAP_SYS_RESOURCE
MemoryDenyWriteExecute=true
ProtectKernelModules=true
ProtectKernelTunables=true
ProtectControlGroups=true
RestrictRealtime=true
RestrictNamespaces=true
RestrictAddressFamilies=AF_INET AF_INET6 AF_UNIX
# redis-server can write to its own config file when in cluster mode so we
# permit writing there by default. If you are not using this feature, it is
# recommended that you replace the following lines with "ProtectSystem=full".
ProtectSystem=true
ReadWriteDirectories=-/etc/redis
[Install]
WantedBy=multi-user.target
Alias=redis.service
This is all running on a physical machine that is not publicly accessible (and the Redis port is filtered by ufw regardless).
Debian GNU/Linux 11 (bullseye) Linux x 5.10.0-19-amd64 #1 SMP Debian 5.10.149-2 (2022-10-21) x86_64 GNU/Linux Filesystem where /var/lib/redis is: ext4 redis-server 5:6.0.16-1+deb11u2 redis-py 4.3.4
I checked the system journal and didn't see anything out of the ordinary from the time the system was last booted from either the kernel or from redis-server. I also did a find / -name '*.rdb' and only /var/lib/redis/dump.rdb comes up.
root@x:~# redis-cli CONFIG GET dir
1) "dir"
2) "/var/lib/redis"
root@x:~# redis-cli CONFIG GET dbfilename
1) "dbfilename"
2) "dump.rdb"
Comment From: oranagra
seems like you didn't follow the right procedure for enabling AOF, see another recent discussion: #12484 we're in the process of improving the documentation, hopefully this will reduce the chance of this mistake. Docs: https://github.com/redis/redis-doc/pull/2521 Config: https://github.com/redis/redis/pull/12506
Comment From: zuiderkwast
@oranagra How hard would it be to add a safe-gard for this, so when redis starts with RDB+AOF enabled and there is an rdb dump but no AOF file, it either refuses to start at all or it loads the rdb dump? Any drawback with such behaviour?
Just because people do this mistake, obviously, and data loss is a sad thing.
Comment From: oranagra
That behavior change can also lead to undesired results in existing deployments.
I.e. someone that creates periodic snapshots, but decided to delete the aof and restart. Or someone with an old rdb file on the disk (and save config disabled).
So either way, to make this case safer, can break another case, and we should decide which one is more important.
Comment From: zuiderkwast
Ok, true, whatever we do, some case is affected. But avoiding data loss is maybe more important?
If the AOF is deleted when Redis is stopped, then maybe users can live with an error like "Possible mistake leading to data loss detected: save and aof enabled but no aof file found and a dump.rdb found. Refusing to start. If you know what you're doing, delete or rename the dump.rdb and try again.". No?
Comment From: enjoy-binbin
we used to discuss it in [#12098](https://github.com/redis/redis/issues/12098#issuecomment-1523235699)
Comment From: jogc
seems like you didn't follow the right procedure for enabling AOF, see another recent discussion: #12484 we're in the process of improving the documentation, hopefully this will reduce the chance of this mistake. Docs: redis/redis-doc#2521 Config: #12506
Got it...I missed that section in the docs