2025-06-12 08:44:38.930 UTC [13] FATAL: could not write to file "pg_wal/xlogtemp.13": No space left on device
ubuntu@dbapp:~$ sudo du -hs /var/lib/postgresql/data/* 231G /var/lib/postgresql/data/pgdata 249G /var/lib/postgresql/data/wal_archive
2025-06-12 08:44:38.930 UTC [13] FATAL: could not write to file "pg_wal/xlogtemp.13": No space left on device
ubuntu@dbapp:~$ sudo du -hs /var/lib/postgresql/data/* 231G /var/lib/postgresql/data/pgdata 249G /var/lib/postgresql/data/wal_archive
| Status | Subtype | Assigned | Task | ||
|---|---|---|---|---|---|
| Open | BUG REPORT | None | T400260 [trove] Postgres uses up to 50% of disk space for wal_archive | ||
| Resolved | BUG REPORT | fnegri | T396724 [trove] Disk full for DBapp instance in glamwikidashboard project |
The same instance crashed last year because the disk filled up: T355138: Rescue DBapp trove instance in glamwikidashboard project
This time it looks slightly different, the wal_archive is taking up 50% of the disk space. Maybe that's normal, reading https://docs.openstack.org/trove/latest/admin/database_management.html it looks like the cleanup only starts when the archive goes over 50%:
if the size is greater than half of the data volume size, in the archive folder
I'm not sure if I can just delete files from wal_archive, so I will attempt resizing the disk first.
sudo OS_PROJECT_ID=glamwikidashboard wmcs-openstack database instance resize volume ee0c90b0-5d21-4d41-9abf-cdabca2787c3 550
This initially failed with
Instance ee0c90b0-5d21-4d41-9abf-cdabca2787c3 is not currently available for an action to be performed (instance status was ACTIVE). (HTTP 422)
But after a few attempts with database instance reset status and database instance restart, the resize volume command above started correctly, and resized the volume.
fnegri@cloudcontrol1007:~$ sudo OS_PROJECT_ID=glamwikidashboard wmcs-openstack database instance list +-----------------------+-------+------------+-------------------+--------+------------------+--------+-----------+------------------------+------+------+ | ID | Name | Datastore | Datastore Version | Status | Operating Status | Public | Addresses | Flavor ID | Size | Role | +-----------------------+-------+------------+-------------------+--------+------------------+--------+-----------+------------------------+------+------+ | ee0c90b0-5d21-4d41- | DBapp | postgresql | 12.7 | RESIZE | | False | | 4a6442de-1ac6-4eca- | 550 | | | 9abf-cdabca2787c3 | | | | | | | | b926-295edb9b7970 | | | +-----------------------+-------+------------+-------------------+--------+------------------+--------+-----------+------------------------+------+------+
After some time, it moved from RESIZE to ACTIVE / SHUTDOWN:
fnegri@cloudcontrol1007:~$ sudo OS_PROJECT_ID=glamwikidashboard wmcs-openstack database instance list +-----------------------+-------+------------+-------------------+--------+------------------+--------+-----------+------------------------+------+------+ | ID | Name | Datastore | Datastore Version | Status | Operating Status | Public | Addresses | Flavor ID | Size | Role | +-----------------------+-------+------------+-------------------+--------+------------------+--------+-----------+------------------------+------+------+ | ee0c90b0-5d21-4d41- | DBapp | postgresql | 12.7 | ACTIVE | SHUTDOWN | False | | 4a6442de-1ac6-4eca- | 550 | | | 9abf-cdabca2787c3 | | | | | | | | b926-295edb9b7970 | | | +-----------------------+-------+------------+-------------------+--------+------------------+--------+-----------+------------------------+------+------+
I tried database instance restart, that moved it to status REBOOT and then ACTIVE / ERROR. I then tried rebooting the VM, doing database instance restart again and this time the volume was mounted, and the database container was restarted.
Postgres is now running but logging this error:
2025-06-12 09:33:23.193 UTC [1] LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432" 2025-06-12 09:33:24.231 UTC [13] LOG: database system was shut down at 2025-06-09 04:48:45 UTC 2025-06-12 09:33:24.473 UTC [1] LOG: database system is ready to accept connections 2025-06-12 09:33:24.824 UTC [18] LOG: archive command failed with exit code 1 2025-06-12 09:33:24.824 UTC [18] DETAIL: The failed archive command was: test ! -f /var/lib/postgresql/data/wal_archive/0000000100001577000000A1 && cp pg_wal/0000000100001577000000A1 /var/lib/postgresql/data/wal_archive/0000000100001577000000A1 2025-06-12 09:33:25.828 UTC [18] LOG: archive command failed with exit code 1 2025-06-12 09:33:25.828 UTC [18] DETAIL: The failed archive command was: test ! -f /var/lib/postgresql/data/wal_archive/0000000100001577000000A1 && cp pg_wal/0000000100001577000000A1 /var/lib/postgresql/data/wal_archive/0000000100001577000000A1 2025-06-12 09:33:26.479 UTC [18] LOG: archive command failed with exit code 1 2025-06-12 09:33:26.479 UTC [18] DETAIL: The failed archive command was: test ! -f /var/lib/postgresql/data/wal_archive/0000000100001577000000A1 && cp pg_wal/0000000100001577000000A1 /var/lib/postgresql/data/wal_archive/0000000100001577000000A1 2025-06-12 09:33:26.480 UTC [18] WARNING: archiving write-ahead log file "0000000100001577000000A1" failed too many times, will try again later
Does it make sense that I still don't get a response when sending a ping command to the host?
@YochayCO not sure, let me try fixing that error first. This is similar to what @taavi saw in T355138: Rescue DBapp trove instance in glamwikidashboard project and apparently deleting one of those archive files got things unstuck.
root@dbapp:/# ls -l /var/lib/postgresql/data/wal_archive/0000000100001577000000A1 -rw------- 1 database database 9940992 Jun 8 05:33 /var/lib/postgresql/data/wal_archive/0000000100001577000000A1 root@dbapp:/# ls -l /var/lib/postgresql/data/pgdata/pg_wal/0000000100001577000000A1 -rw-r-xr-x 1 database database 16777216 Jun 8 06:07 /var/lib/postgresql/data/pgdata/pg_wal/0000000100001577000000A1
The file in wal_archive was smaller so probably an incomplete copy. I removed it with
mv /var/lib/postgresql/data/wal_archive/0000000100001577000000A1 /root
After that, the error stopped being logged.
Copying from what @taavi did in T355138, I cleaned up the wal_archive files with:
I have no name!@550490a61acf:/var/lib/postgresql/data$ pg_controldata | grep "Latest checkpoint's REDO WAL file" Latest checkpoint's REDO WAL file: 000000010000157900000009 I have no name!@550490a61acf:/var/lib/postgresql/data$ pg_archivecleanup -d /var/lib/postgresql/data/wal_archive/ 000000010000157900000009
After that the disk space is much better:
I have no name!@47cbec5565d8:/$ du -hs /var/lib/postgresql/data/* 225G /var/lib/postgresql/data/pgdata 17M /var/lib/postgresql/data/wal_archive
@YochayCO I can successfully connect to the database now. ping does not work, but I think some firewall is blocking that. Connecting to the Postgres port works for me:
psql -h 7ot336yvrek.svc.trove.eqiad1.wikimedia.cloud -p 5432 -U postgres Password for user postgres: psql (17.4 (Ubuntu 17.4-1.pgdg24.04+2), server 12.7 (Debian 12.7-1.pgdg100+1))
Awesome, many thanks!
Does it make sense that maybe I don't have permissions to ssh to the db host?
I can see it as DbApp in my wikiglamdashboard project, so I guess I should have access from the shell too.
Maybe I could reconfigure the logs & archive settings from the Horizon interface, but I'll have more observability from ssh.
@YochayCO We don't have a way at the moment to grant SSH access to the Trove DB hosts, the only way we can SSH is through a shared admin key that gives access to all DBs. I guess that's a feature not a bug, as Trove is a managed service. :)
If we find that the current settings require 50% of the space to be reserved for wal_archive, we should probably change that setting for everybody.
I would also check if the database size is increasing more than expected.
I did some "hacks" for harbor on this too, might be a better way of doing the same, but helped reduce the usage with the drawback that we get no backups (that were not working at least back then) T343683: [toolsbeta.harbor] trove postrgres DB out of space, v2
pgdata size is constant, but wal_archive is increasing quite rapidly:
ubuntu@dbapp:~$ sudo du -hs /var/lib/postgresql/data/* 226G /var/lib/postgresql/data/pgdata 57G /var/lib/postgresql/data/wal_archive
Most of it is in the pgdata/base directory:
ubuntu@dbapp:~$ sudo du -hs /var/lib/postgresql/data/pgdata/base/ 225G /var/lib/postgresql/data/pgdata/base/
I tried a VACUUM but the pgdata size did not change. While the vacuum was running the wal_archive increased from 57 to 63 GB:
ubuntu@dbapp:~$ docker exec -it database vacuumdb -U postgres --all --echo [...] ubuntu@dbapp:~$ sudo du -hs /var/lib/postgresql/data/* 226G /var/lib/postgresql/data/pgdata 63G /var/lib/postgresql/data/wal_archive
I suspect maybe the problem is in the app and not in the db configuration...
I see that we open many 'REFRESH MATERIALIZED VIEW visualizations_stats' queries simultaneously (in multiple connections, that is unavoidable in the current architecture).
I saw today 4 of these connections open for more than an hour.
Now the active connections are down to 1, but maybe at other times its even worse (the application allows a maximum of 100).
I'll consult with the previous supporter to reconfirm this - but what do you think?
If that's indeed the problem, I see two easy options:
@YochayCO I did keep an eye on the disk usage in the past few days. wal_archive kept on growing quite fast, but as I expected it was cleaned up automatically when it reached 50% of the disk space (as per the Trove docs).
So it reached about 550/2 = 275GB then it went down to close to zero. Then it started growing again and it's currently at 52GB.
This is now working fine because I enlarged the partition to 550G, so the wal_archive is free to grow up to 50%, get cleaned up, and grow again. But if the database size (currently stable at 228G) grows to occupy more than 50% of the available space, then wal_archive will not be cleaned up until it reaches 50%, and the disk will run out of space, like it happened last week.
The 50% threshold in Trove does not seem very sensible to me, I'm considering raising this as an issue upstream. In the meantime, we can do two things:
Change to: 'REFRESH MATERIALIZED VIEW CONCURRENTLY'. GPT is very convincing that it might help.
I'm less convinced, but feel free to try. :)
I want to do some more research, it should be possible to analyze the existing WAL files to see which operations are contained in there and which ones take up so much space. I will try to do it next week!
I've tried adding archive_mode = off via https://horizon.wikimedia.org/project/database_configurations/{id} as you suggested,
It's not one of the selectable options.
Regarding the fast growth of wal_archive, my guess is that is is connected to the "REFRESH MATERIALIZED VIEW" operation.
It is ran every day for each organization, which currently has its own "database" (not just own table) inside the postgres instance.
To my understanding (which still, might not be so accurate), this is a heavy operation and I think that this is what's causing the wal_archive to fill up quickly.
There is no problem by my side, to reduce the wal_archive allocated size, or even disable it completely as you suggested. I think it is a good idea for our needs.
Apologies for the late reply, this is still in my backlog but I couldn't make much progress until now.
I opened an upstream bug report at https://storyboard.openstack.org/#!/story/2011496
While we wait for a reply there, I still think it's a good idea to disable archive_mode permanently for your instance. You are right that unfortunately it is not possible to disable it from the "configuration group" in Horizon. I can disable it by manually editing /etc/postgresql/postgresql.conf, although this is sub-optimal because that file is likely be reset the next time we upgrade the base image used by Trove. We don't upgrade those images very often, so it's probably ok as an interim solution.
Regarding the fast growth of wal_archive, my guess is that is is connected to the "REFRESH MATERIALIZED VIEW" operation.
I agree this is likely to be the cause. I tried analyzing the WAL files and it's not easy to say that with absolute certainty because they are hard to parse, but I think they do look consistent with frequent refreshes of big materialized views.
Change to: 'REFRESH MATERIALIZED VIEW CONCURRENTLY'. GPT is very convincing that it might help.
Adding CONCURRENTLY is not going to help, unless we also decrease the wal_level to minimal, which is not compatible with WAL archiving. So I would just disable archive_mode, without adding CONCURRENTLY and without changing wal_level.
@YochayCO I have two questions:
Hi, thank you for your efforts!
I really don't know much about the CONCURRENTLY so yeah, I trust you more than I trust GPT ;)
Regarding the time for the reconfiguration, it is better if we do it after 12:00 UTC because of the daily script that I'm hopeful will finish by then.
I'm available every day until 16:00 UTC, and more flexible on Tuesday and Wednesday.
Let's schedule a time, I don't trust the server to reconnect automatically - though I'm positive it probably will.
@YochayCO let's schedule the reconfiguration for this Wednesday, 2025-07-23 at 12:00 UTC. We can sync in this task and/or in IRC, and postpone it to a little later in case the daily script is still running.
Yes you can delete it. Will you attempt to create a working one later? I think it is better if we have a backup for the long run.
My plan was not to create one, because the backup feature in Trove is relying on archive_mode being enabled. It's creating incremental backups with point-in-time recovery, which are very nice but rely on keeping an archive of WAL logs. We also have disk-level backups that we run nightly and we keep for 7 days (only accessible to admins). If you are interested in re-enabling the Trove backups, I will have a look if I can find out why that one failed.
I believe disk-level backups are enough :)
Tomorrow it is then. Updating in this task is fine.
If you think I'll be required while you operate maybe IRC is better for notifications.
But I guess I'll mostly be needed to look at the GLAM app & services to see if anything needs a reboot, after you finish the operation.
I deleted the failed backup. @YochayCO waiting for your ok before changing the archive_mode setting and restarting the database.
Looking healthy, I'll supervise it tomorrow as well just in case :) Thank you @fnegri
Thank you @YochayCO !
For the record, I couldn't find any cleaner way to disable archive_mode than manually editing /etc/postgresql/postgresql.conf in the VM dbapp.trove.eqiad1.wikimedia.cloud:
# Hack: forcing this to off to reduce disk space usage T396724 archive_mode = off # enables archiving; off, on, or always
This change is likely to get overwritten when the Trove instance is upgraded to a newer PostgreSQL version (currently running PostgreSQL 12.7). We don't plan to upgrade it soon, but it will happen eventually.
I'm gonna increase the volume size to 1000GB, just to be on the safe side. This should make sure there's enough space for the DB even if we were to lose my change and wal_archive starts growing again. @YochayCO this will cause another brief downtime.
I also opened T400260: [trove] Postgres uses up to 50% of disk space for wal_archive to track the upstream issue and discuss other solutions and workarounds.
Hmm the resize failed:
fnegri@cloudcontrol1007:~$ sudo OS_PROJECT_ID=glamwikidashboard wmcs-openstack database instance resize volume ee0c90b0-5d21-4d41-9abf-cdabca2787c3 1000
The quota shows 1000 in use, but the volume is still at 550.
Ok a second attempt is now resizing the disk, the db should be back in a couple minutes.
Resize completed. I was hoping it would be smoother, apologies for the downtime. Things should be back to normal now (with 1000GB of disk space).