Backup data to webdav share failed

NethServer Version: 7.8
Module: backup
Since 2 days I see my backup has failed. I use the backup option to a remote webdav share. This has worked for months without any issues. Suddenly, without having changed anything to the settings, mounting the webdav share fails and thus, the whole backup fails.

log from backup-data:
2018-01-03 01:00:01 - START - Backup data started
2018-01-03 01:00:22 - ERROR - Error while mounting https://webdavstorage.tld
: /sbin/mount.davfs: Mounting failed. 302 Found
2018-01-03 01:00:22 - ERROR - Event pre-backup-data failed - 1

Backup: backup-data
Backup started at 2020-09-25 01:00:03
Event pre-backup-data: FAIL
Backup status: FAIL

The credentials are good since I can log in with them through web interface, (the webdav storage is a cloud service based on owncloud)

Manually mounting the webdav share is working just fine:

[root@ns7 ~]# mount -t davfs -o noexec https://webdavstorage.tld/remote.php/webdav/ /root/dav
Please enter the username to authenticate with server
https://webdavstorage.tld/remote.php/webdav/ or hit enter for none.
Username: user
Please enter the password to authenticate user robb with server
https://webdavstorage.tld/remote.php/webdav/ or hit enter for none.
Password:
/sbin/mount.davfs: Warning: canā€™t write entry into mtab, but will mount the file system anyway

Looking what ā€˜302 Foundā€™ is, it turns out it is a redirect.
What could be wrong? This has worked for months but suddenly 2 days ago it broke.

Does webdav service is hosted by a custom solution or you are buying a space?

The webdav service is a commercial solution from a provider here in the Netherlands.
I donā€™t see an update of nethserver-backup-data in my logs so I am completely puzzled here.

Maybe the provider changed something? Did you check?

Manually mounting the webdav share is going just fine, see posted logs. Nothing has changed in the backup settings. What I find weird is the ā€˜302 Foundā€™ which means there seemingly occurs a redirect somewhere.
I can inquire with the hosting provider for the webdav instanceā€¦

Oh I see I posted the wrong log in my opening post. I will change it with the content of the correct one (see date)
Unfortunately there is even less info in the correct log:

Backup: backup-data
Backup started at 2020-09-25 01:00:03
Event pre-backup-data: FAIL
Backup status: FAIL

How can I get a more verbose log?

NethServer mount does:

/bin/mount -t davfs "$webdavurl" $mntdir

You added -o noexec, try without it. But it shouldnā€™t ask for a password, itā€™s stored in /etc/davfs, please check also the content of that dir.

mounting the exact command what Nethserver does just works when doing this manually (I used /root/dav as testing location to mount the share):

/bin/mount -t davfs https://webdavstorage.tld/remote.php/webdav/ /root/dav
Please enter the username to authenticate with server
https://webdavstorage.tld/remote.php/webdav/ or hit enter for none.
Username: user
Please enter the password to authenticate user user with server
https://webdavstorage.tld/remote.php/webdav/ or hit enter for none.
Password:
/sbin/mount.davfs: Warning: canā€™t write entry into mtab, but will mount the file system anyway

@filippo_carletti would it be possible to increase the verbosity of the logs and run a manual backup, so I can see more detail what goes wrong? How to set the verbosity?

Do you know if something has changed to the pre-backupscript for nethserver-backup-data? (since sept 20th)
/edit can answer that myself: last month there has been no changes in the code: Pulse Ā· NethServer/nethserver-backup-data Ā· GitHub

I donā€™t think you can increase the verbosity, but you can simply run the mount script, without running a backup. Itā€™s /etc/e-smith/events/actions/mount-webdav.
You can copy it and try hacking it.

Itā€™s is beyond my comprehension why I can manually mount the webdav share and the script fails. Also no error output is not helping.
And why it suddenly fails? after months and months without issues.?

Is the backup mount that fails or one of the pre-backup-data events (like the mysql dump /etc/e-smith/events/actions/mysql-dump-tables)?

ll /etc/e-smith/events/pre-backup-data/

Hereā€™s an example on how it can be tested:

1 Like

I just had a look at /var/log/messages.
This is an exerpt from when the backup staill was OK:

Sep 21 01:00:04 ns7 esmith::event[1467]: Event: pre-backup-data backup-data
Sep 21 01:00:04 ns7 esmith::event[1467]: ===== Report for configuration backup =====
Sep 21 01:00:04 ns7 esmith::event[1467]: Backup started at 2020-09-21 01:00:04
Sep 21 01:00:04 ns7 esmith::event[1477]: Event: pre-backup-config
Sep 21 01:00:05 ns7 esmith::event[1477]: expanding /etc/backup-config.d/nethserver-sssd.include
Sep 21 01:00:05 ns7 esmith::event[1477]: Action: /etc/e-smith/events/actions/generic_template_expand SUCCESS [0.36406]
Sep 21 01:00:07 ns7 esmith::event[1477]: Action: /etc/e-smith/events/pre-backup-config/S40nethserver-dc-pre-backup SUCCESS [2.216226]
Sep 21 01:00:08 ns7 esmith::event[1477]: Action: /etc/e-smith/events/pre-backup-config/S40nethserver-mail-shrmbx-cfgbackup SUCCESS [0.838621]
Sep 21 01:00:08 ns7 esmith::event[1477]: Action: /etc/e-smith/events/pre-backup-config/S40nethserver-sssd-backup-tdb SUCCESS [0.047163]
Sep 21 01:00:09 ns7 systemd: Removed slice User Slice of apache.
Sep 21 01:00:18 ns7 esmith::event[1477]: Action: /etc/e-smith/events/pre-backup-config/S50nethserver-backup-config-list-packages SUCCESS [10.330284]
Sep 21 01:00:18 ns7 esmith::event[1477]: Event: pre-backup-config SUCCESS
Sep 21 01:00:18 ns7 esmith::event[1467]: Event pre-backup-config: SUCCESS
Sep 21 01:00:28 ns7 esmith::event[1467]: Action backup-config-execute: SUCCESS
Sep 21 01:00:28 ns7 esmith::event[2061]: Event: post-backup-config
Sep 21 01:00:28 ns7 esmith::event[2061]: Action: /etc/e-smith/events/post-backup-config/S40nethserver-dc-post-backup SUCCESS [0.05656]
Sep 21 01:00:28 ns7 esmith::event[2061]: Event: post-backup-config SUCCESS
Sep 21 01:00:28 ns7 esmith::event[1467]: Event post-backup-config: SUCCESS
Sep 21 01:00:28 ns7 esmith::event[1467]: Backup status: SUCCESS
Sep 21 01:00:28 ns7 esmith::event[1467]: Backup ended at 2020-09-21 01:00:28
Sep 21 01:00:28 ns7 esmith::event[1467]: Time elapsed: 0 hours, 0 minutes, 24 seconds
Sep 21 01:00:28 ns7 esmith::event[1467]: Action: /etc/e-smith/events/pre-backup-data/S20nethserver-backup-config-predatabackup SUCCESS [24.866373]
Sep 21 01:00:33 ns7 esmith::event[1467]: Action: /etc/e-smith/events/pre-backup-data/S50mysql-dump-tables SUCCESS [4.567789]
Sep 21 01:00:33 ns7 su: (to ejabberd) root on none
Sep 21 01:00:33 ns7 su: (to ejabberd) root on none
Sep 21 01:00:34 ns7 esmith::event[1467]: Action: /etc/e-smith/events/pre-backup-data/S50nethserver-ejabberd-backup SUCCESS [1.134311]
Sep 21 01:00:34 ns7 su: (to postgres) root on none
Sep 21 01:00:35 ns7 esmith::event[1467]: Action: /etc/e-smith/events/pre-backup-data/S50nethserver-mattermost-backup SUCCESS [1.215951]
Sep 21 01:00:37 ns7 esmith::event[1467]: Action: /etc/e-smith/events/pre-backup-data/S80nethserver-sogo-backup-users SUCCESS [2.147823]
Sep 21 01:00:37 ns7 esmith::event[1467]: Event: pre-backup-data SUCCESS

And this is when it went wrong:

Sep 27 01:00:03 ns7 esmith::event[5970]: Event: pre-backup-data backup-data
Sep 27 01:00:03 ns7 esmith::event[5970]: ===== Report for configuration backup =====
Sep 27 01:00:03 ns7 esmith::event[5970]: Backup started at 2020-09-27 01:00:03
Sep 27 01:00:04 ns7 esmith::event[5976]: Event: pre-backup-config
Sep 27 01:00:04 ns7 esmith::event[5976]: expanding /etc/backup-config.d/nethserver-sssd.include
Sep 27 01:00:04 ns7 esmith::event[5976]: Action: /etc/e-smith/events/actions/generic_template_expand SUCCESS [0.233352]
Sep 27 01:00:05 ns7 esmith::event[5976]: Action: /etc/e-smith/events/pre-backup-config/S40nethserver-dc-pre-backup SUCCESS [0.8888]
Sep 27 01:00:05 ns7 systemd: Removed slice User Slice of apache.
Sep 27 01:00:05 ns7 esmith::event[5976]: Action: /etc/e-smith/events/pre-backup-config/S40nethserver-mail-shrmbx-cfgbackup SUCCESS [0.382487]
Sep 27 01:00:05 ns7 esmith::event[5976]: Action: /etc/e-smith/events/pre-backup-config/S40nethserver-sssd-backup-tdb SUCCESS [0.010839]
Sep 27 01:00:12 ns7 esmith::event[5976]: Action: /etc/e-smith/events/pre-backup-config/S50nethserver-backup-config-list-packages SUCCESS [7.129089]
Sep 27 01:00:12 ns7 esmith::event[5976]: Event: pre-backup-config SUCCESS
Sep 27 01:00:12 ns7 esmith::event[5970]: Event pre-backup-config: SUCCESS
Sep 27 01:00:21 ns7 esmith::event[5970]: Action backup-config-execute: SUCCESS
Sep 27 01:00:21 ns7 esmith::event[6373]: Event: post-backup-config
Sep 27 01:00:21 ns7 esmith::event[6373]: Action: /etc/e-smith/events/post-backup-config/S40nethserver-dc-post-backup SUCCESS [0.058435]
Sep 27 01:00:21 ns7 esmith::event[6373]: Event: post-backup-config SUCCESS
Sep 27 01:00:21 ns7 esmith::event[5970]: Event post-backup-config: SUCCESS
Sep 27 01:00:21 ns7 esmith::event[5970]: Backup status: SUCCESS
Sep 27 01:00:21 ns7 esmith::event[5970]: Backup ended at 2020-09-27 01:00:21
Sep 27 01:00:21 ns7 esmith::event[5970]: Time elapsed: 0 hours, 0 minutes, 18 seconds
Sep 27 01:00:21 ns7 esmith::event[5970]: Action: /etc/e-smith/events/pre-backup-data/S20nethserver-backup-config-predatabackup SUCCESS [17.951548]
Sep 27 01:00:25 ns7 esmith::event[5970]: Action: /etc/e-smith/events/pre-backup-data/S50mysql-dump-tables SUCCESS [4.0896]
Sep 27 01:00:25 ns7 su: (to ejabberd) root on none
Sep 27 01:00:26 ns7 su: (to ejabberd) root on none
Sep 27 01:00:26 ns7 esmith::event[5970]: Action: /etc/e-smith/events/pre-backup-data/S50nethserver-ejabberd-backup SUCCESS [1.075685]
Sep 27 01:00:26 ns7 su: (to postgres) root on none
Sep 27 01:00:27 ns7 esmith::event[5970]: pg_dump: error: connection to database ā€œmattermostā€ failed: FATAL: database ā€œmattermostā€ does not exist
Sep 27 01:00:27 ns7 esmith::event[5970]: Action: /etc/e-smith/events/pre-backup-data/S50nethserver-mattermost-backup FAILED: 1 [0.358902]
Sep 27 01:00:29 ns7 esmith::event[5970]: Action: /etc/e-smith/events/pre-backup-data/S80nethserver-sogo-backup-users SUCCESS [2.364558]
Sep 27 01:00:29 ns7 esmith::event[5970]: Event: pre-backup-data FAILED
Sep 27 01:00:38 ns7 collectd[13997]: [FAILURE] system:backup:failure: backup state is failure

Looks like mattermost database is the culprit?

1 Like

Does mattermost work?

Recently there was a mattermost update to newer postgresql, maybe something went wrong?

No, I get a ā€˜service unavailableā€™
Then that update probably went wrong.

Is there something in the logfile /opt/mattermost/logs/mattermost.log ?

After writing this post I noticed that my /var/opt/rh/rh-postgresql12/lib/pgsql/data/pg_hba.conf had other entries before so maybe itā€™s enough to expand the template and restart the service:

expand-template /var/opt/rh/rh-postgresql12/lib/pgsql/data/pg_hba.conf

systemctl restart rh-postgresql12-postgresql mattermost

ā€¦

I have a similar issue. I solved it by removing and recreating the data dir in postgresql12 and restoring the DB backup. Just restoring/recreating the mattermost database didnā€™t work.

Please check if you already have the mattermost database in postgresql12:

su - postgres -c "scl enable rh-postgresql12 -- psql --port=55434"
\l

Exit with:

\q

Stop mattermost:

systemctl stop mattermost

If thereā€™s already a backup /var/lib/nethserver/mattermost/backup/mattermost.sql please rename/move it.

To create a backup of the mattermost DB:

/etc/e-smith/events/actions/nethserver-mattermost-backup

Remove pgsql data dir content:

rm -rf /var/opt/rh/rh-postgresql12/lib/pgsql/data/*

Recreate postgres database:

signal-event nethserver-postgresql12-update

Restore mattermost database:

/etc/e-smith/events/actions/nethserver-mattermost-restore

Start mattermost:

systemctl start mattermost

1 Like

When I try to backup the mattermost database, there is no database.

pg_dump: error: connection to database ā€œmattermostā€ failed: FATAL: database ā€œmattermostā€ does not exist

However, there is a backup of the database in /var/log/nethserver/mattermost/backup/

There probably is more wrong here.

Or less.

Maybe itā€™s just enough to restore the mattermost DB thatā€™s already there.

systemctl stop mattermost

/etc/e-smith/events/actions/nethserver-mattermost-restore

systemctl start mattermost

This fails with this output:

/etc/e-smith/events/actions/nethserver-mattermost-restore
psql: error: could not connect to server: could not connect to server: No such file or directory
Is the server running locally and accepting
connections on Unix domain socket ā€œ/var/run/postgresql/.s.PGSQL.55434ā€?
psql: error: could not connect to server: could not connect to server: No such file or directory
Is the server running locally and accepting
connections on Unix domain socket ā€œ/var/run/postgresql/.s.PGSQL.55434ā€?

It seems postgres12 is not running, please check with

systemctl status rh-postgresql12-postgresql -l

Correct. postgresql is not started. But starting with systemctl start postgresql doesnā€™t bring it to life.