Data backup error

indra · June 5, 2018, 5:55am

Since last week my data backup fails with Pre backup scripts status: ERROR

This is what messages log says:

Jun  5 07:43:48 mynethserver esmith::event[20810]: Action: /etc/e-smith/events/actions/generic_template_expand SUCCESS [0.292395]
Jun  5 07:43:49 mynethserver esmith::event[20810]: Action: /etc/e-smith/events/pre-backup-config/S40nethserver-dc-pre-backup SUCCESS [0.669101]
Jun  5 07:43:49 mynethserver esmith::event[20810]: Action: /etc/e-smith/events/pre-backup-config/S40nethserver-mail-shrmbx-cfgbackup SUCCESS [0.014874]
Jun  5 07:43:49 mynethserver esmith::event[20810]: Action: /etc/e-smith/events/pre-backup-config/S40nethserver-sssd-backup-tdb SUCCESS [0.008996]
Jun  5 07:43:50 mynethserver esmith::event[20810]: Action: /etc/e-smith/events/pre-backup-config/S50nethserver-backup-config-list-packages SUCCESS [1.298417]
Jun  5 07:43:50 mynethserver esmith::event[20810]: Event: pre-backup-config SUCCESS
Jun  5 07:43:56 mynethserver esmith::event[21303]: Event: post-backup-config
Jun  5 07:43:56 mynethserver esmith::event[21303]: Action: /etc/e-smith/events/post-backup-config/S40nethserver-dc-post-backup SUCCESS [0.03245]
Jun  5 07:43:56 mynethserver esmith::event[21303]: Event: post-backup-config SUCCESS
Jun  5 07:43:56 mynethserver esmith::event[20799]: Action: /etc/e-smith/events/pre-backup-data/S20nethserver-backup-config-predatabackup SUCCESS [9.152735]
Jun  5 07:43:57 mynethserver kernel: duc[21327]: segfault at 7feea34c3d60 ip 00007fee517f1706 sp 00007fff4b19da58 error 4 in libc-2.17.so[7fee516a5000+1b8000]
Jun  5 07:43:57 mynethserver esmith::event[20799]: /etc/e-smith/events/pre-backup-data/S20nethserver-restore-data-duc-index: line 47: 21327 Segmentation fault      /usr/bin/duc index $INDEX_DIR --database=$DB_FILE
Jun  5 07:43:57 mynethserver esmith::event[20799]: Path /root not found in database
Jun  5 07:43:57 mynethserver esmith::event[20799]: Requested path not found
Jun  5 07:43:57 mynethserver esmith::event[20799]: Path /usr/share/nextcloud/config/config.php not found in database
Jun  5 07:43:57 mynethserver esmith::event[20799]: Requested path not found
Jun  5 07:43:57 mynethserver esmith::event[20799]: Path /var/lib/collectd not found in database
Jun  5 07:43:57 mynethserver esmith::event[20799]: Requested path not found
Jun  5 07:43:57 mynethserver esmith::event[20799]: Path /var/lib/nethserver not found in database
Jun  5 07:43:57 mynethserver esmith::event[20799]: Requested path not found
Jun  5 07:43:57 mynethserver esmith::event[20799]: Path /var/lib/sogo/backups not found in database
Jun  5 07:43:57 mynethserver esmith::event[20799]: Requested path not found
Jun  5 07:43:57 mynethserver esmith::event[20799]: Path /var/spool/amavisd/.spamassassin not found in database
Jun  5 07:43:57 mynethserver esmith::event[20799]: Requested path not found
Jun  5 07:43:57 mynethserver esmith::event[20799]: Path /var/www/html/freepbx not found in database
Jun  5 07:43:57 mynethserver esmith::event[20799]: Requested path not found
Jun  5 07:43:57 mynethserver esmith::event[20799]: Action: /etc/e-smith/events/pre-backup-data/S20nethserver-restore-data-duc-index SUCCESS [0.959957]
Jun  5 07:44:05 mynethserver esmith::event[20799]: Action: /etc/e-smith/events/pre-backup-data/S50mysql-dump-tables SUCCESS [7.743312]
Jun  5 07:44:05 mynethserver esmith::event[20799]: /etc/e-smith/events/pre-backup-data/S50nethserver-ibays-dump-acls: line 24: getfacl: command not found
Jun  5 07:44:05 mynethserver esmith::event[20799]: Action: /etc/e-smith/events/pre-backup-data/S50nethserver-ibays-dump-acls FAILED: 127 [0.004168]
Jun  5 07:44:05 mynethserver esmith::event[20799]: Action: /etc/e-smith/events/pre-backup-data/S70mount-cifs SUCCESS [0.219644]
Jun  5 07:44:05 mynethserver esmith::event[20799]: Action: /etc/e-smith/events/pre-backup-data/S70mount-nfs SUCCESS [0.217766]
Jun  5 07:44:06 mynethserver esmith::event[20799]: Action: /etc/e-smith/events/pre-backup-data/S70mount-usb SUCCESS [0.155373]
Jun  5 07:44:06 mynethserver esmith::event[20799]: Action: /etc/e-smith/events/pre-backup-data/S70mount-webdav SUCCESS [0.159597]
Jun  5 07:44:17 mynethserver esmith::event[20799]: Action: /etc/e-smith/events/pre-backup-data/S80nethserver-sogo-backup-users SUCCESS [11.388148]
Jun  5 07:44:17 mynethserver esmith::event[20799]: Event: pre-backup-data FAILED

giacomo · June 5, 2018, 8:11am

It seems that duc is having problems, try to clean the cache:

rm -f /var/cache/duc/*

indra · June 5, 2018, 8:38am

Thank you, but didn’t seem to work.

Tried
~]# rm -f /var/cache/duc/*
~]# /sbin/e-smith/backup-data

More log messages :

Jun  5 10:30:52 mynethserver esmith::event[25174]: Event: pre-backup-data
Jun  5 10:30:52 mynethserver esmith::event[25199]: Event: pre-backup-config
Jun  5 10:30:52 mynethserver esmith::event[25199]: expanding /etc/backup-config.d/nethserver-sssd.include
Jun  5 10:30:52 mynethserver dbus[1677]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service'
Jun  5 10:30:52 mynethserver dbus-daemon: dbus[1677]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service'
Jun  5 10:30:52 mynethserver systemd: Starting Time & Date Service...
Jun  5 10:30:52 mynethserver dbus[1677]: [system] Successfully activated service 'org.freedesktop.timedate1'
Jun  5 10:30:52 mynethserver dbus-daemon: dbus[1677]: [system] Successfully activated service 'org.freedesktop.timedate1'
Jun  5 10:30:52 mynethserver systemd: Started Time & Date Service.
Jun  5 10:30:52 mynethserver esmith::event[25199]: Action: /etc/e-smith/events/actions/generic_template_expand SUCCESS [0.43774]
Jun  5 10:30:53 mynethserver nmbd[2767]: [2018/06/05 10:30:53.195675,  0] ../source3/libsmb/nmblib.c:873(send_udp)
Jun  5 10:30:53 mynethserver nmbd[2767]:  Packet send failed to 192.168.122.255(137) ERRNO=Operation not permitted
Jun  5 10:30:53 mynethserver nmbd[2767]: [2018/06/05 10:30:53.195812,  0] ../source3/nmbd/nmbd_packets.c:179(send_netbios_packet)
Jun  5 10:30:53 mynethserver nmbd[2767]:  send_netbios_packet: send_packet() to IP 192.168.122.255 port 137 failed
Jun  5 10:30:53 mynethserver nmbd[2767]: [2018/06/05 10:30:53.195864,  0] ../source3/nmbd/nmbd_namequery.c:245(query_name)
Jun  5 10:30:53 mynethserver nmbd[2767]:  query_name: Failed to send packet trying to query name NOBLE-HOUSE<1d>
Jun  5 10:30:53 mynethserver nmbd[2767]: [2018/06/05 10:30:53.196457,  0] ../source3/libsmb/nmblib.c:873(send_udp)
Jun  5 10:30:53 mynethserver nmbd[2767]:  Packet send failed to 192.168.122.255(138) ERRNO=Operation not permitted
Jun  5 10:30:53 mynethserver esmith::event[25199]: Action: /etc/e-smith/events/pre-backup-config/S40nethserver-dc-pre-backup SUCCESS [0.60056]
Jun  5 10:30:53 mynethserver esmith::event[25199]: Action: /etc/e-smith/events/pre-backup-config/S40nethserver-mail-shrmbx-cfgbackup SUCCESS [0.014674]
Jun  5 10:30:53 mynethserver esmith::event[25199]: Action: /etc/e-smith/events/pre-backup-config/S40nethserver-sssd-backup-tdb SUCCESS [0.0087]
Jun  5 10:30:54 mynethserver esmith::event[25199]: Action: /etc/e-smith/events/pre-backup-config/S50nethserver-backup-config-list-packages SUCCESS [1.205658]
Jun  5 10:30:54 mynethserver esmith::event[25199]: Event: pre-backup-config SUCCESS
Jun  5 10:31:00 mynethserver esmith::event[25625]: Event: post-backup-config
Jun  5 10:31:00 mynethserver esmith::event[25625]: Action: /etc/e-smith/events/post-backup-config/S40nethserver-dc-post-backup SUCCESS [0.029812]
Jun  5 10:31:00 mynethserver esmith::event[25625]: Event: post-backup-config SUCCESS
Jun  5 10:31:00 mynethserver esmith::event[25174]: Action: /etc/e-smith/events/pre-backup-data/S20nethserver-backup-config-predatabackup SUCCESS [8.698015]
Jun  5 10:31:01 mynethserver systemd: Created slice User Slice of sogo.
Jun  5 10:31:01 mynethserver systemd: Starting User Slice of sogo.
Jun  5 10:31:01 mynethserver systemd: Started Session 458 of user sogo.
Jun  5 10:31:01 mynethserver systemd: Starting Session 458 of user sogo.
Jun  5 10:31:01 mynethserver systemd: Created slice User Slice of asterisk.
Jun  5 10:31:01 mynethserver systemd: Starting User Slice of asterisk.
Jun  5 10:31:01 mynethserver systemd: Started Session 459 of user asterisk.
Jun  5 10:31:01 mynethserver systemd: Starting Session 459 of user asterisk.
Jun  5 10:31:01 mynethserver systemd: Removed slice User Slice of asterisk.
Jun  5 10:31:01 mynethserver systemd: Stopping User Slice of asterisk.
Jun  5 10:31:01 mynethserver systemd: Removed slice User Slice of sogo.
Jun  5 10:31:01 mynethserver systemd: Stopping User Slice of sogo.
Jun  5 10:31:01 mynethserver esmith::event[25174]: fatal error: out of memory
Jun  5 10:31:01 mynethserver esmith::event[25174]: Path /root not found in database
Jun  5 10:31:01 mynethserver esmith::event[25174]: Requested path not found
Jun  5 10:31:01 mynethserver esmith::event[25174]: Path /usr/share/nextcloud/config/config.php not found in database
Jun  5 10:31:01 mynethserver esmith::event[25174]: Requested path not found
Jun  5 10:31:01 mynethserver esmith::event[25174]: Path /var/lib/collectd not found in database
Jun  5 10:31:01 mynethserver esmith::event[25174]: Requested path not found
Jun  5 10:31:01 mynethserver esmith::event[25174]: Path /var/lib/nethserver not found in database
Jun  5 10:31:01 mynethserver esmith::event[25174]: Requested path not found
Jun  5 10:31:01 mynethserver esmith::event[25174]: Path /var/lib/sogo/backups not found in database
Jun  5 10:31:01 mynethserver esmith::event[25174]: Requested path not found
Jun  5 10:31:01 mynethserver esmith::event[25174]: Path /var/spool/amavisd/.spamassassin not found in database
Jun  5 10:31:01 mynethserver esmith::event[25174]: Requested path not found
Jun  5 10:31:01 mynethserver esmith::event[25174]: Path /var/www/html/freepbx not found in database
Jun  5 10:31:01 mynethserver esmith::event[25174]: Requested path not found
Jun  5 10:31:01 mynethserver esmith::event[25174]: Action: /etc/e-smith/events/pre-backup-data/S20nethserver-restore-data-duc-index SUCCESS [0.928276]
Jun  5 10:31:08 mynethserver esmith::event[25174]: Action: /etc/e-smith/events/pre-backup-data/S50mysql-dump-tables SUCCESS [7.258978]
Jun  5 10:31:08 mynethserver esmith::event[25174]: /etc/e-smith/events/pre-backup-data/S50nethserver-ibays-dump-acls: line 24: getfacl: command not found
Jun  5 10:31:08 mynethserver esmith::event[25174]: Action: /etc/e-smith/events/pre-backup-data/S50nethserver-ibays-dump-acls FAILED: 127 [0.005621]
Jun  5 10:31:09 mynethserver esmith::event[25174]: Action: /etc/e-smith/events/pre-backup-data/S70mount-cifs SUCCESS [0.177867]
Jun  5 10:31:09 mynethserver esmith::event[25174]: Action: /etc/e-smith/events/pre-backup-data/S70mount-nfs SUCCESS [0.161223]
Jun  5 10:31:09 mynethserver esmith::event[25174]: Action: /etc/e-smith/events/pre-backup-data/S70mount-usb SUCCESS [0.154355]
Jun  5 10:31:09 mynethserver esmith::event[25174]: Action: /etc/e-smith/events/pre-backup-data/S70mount-webdav SUCCESS [0.21899]
Jun  5 10:31:20 mynethserver esmith::event[25174]: Action: /etc/e-smith/events/pre-backup-data/S80nethserver-sogo-backup-users SUCCESS [10.854568]
Jun  5 10:31:20 mynethserver esmith::event[25174]: Event: pre-backup-data FAILED

giacomo · June 5, 2018, 10:30am

It worked But you have now another issue: missing dependency.
Are you sure you don’t have problems on disks?

By the way, you can try fixing with:

yum install acl

filippo_carletti · June 5, 2018, 10:36am

I think that duc has more problems, or the system has not enough memory.

indra · June 5, 2018, 11:06am

Ok that did seems to fix it, at least now starting the backup manually takes very long time and Dashboard say it’s running [START - STEP - etc… ]
I think I accidently removed acl with
yum autoremove

indra · June 5, 2018, 11:09am

Although it does seem to work now, still something strange is happening with the duc thing it think.
Here’s what it says now :

Jun  5 13:00:53 mynethserver esmith::event[1205]: Action: /etc/e-smith/events/pre-backup-data/S20nethserver-backup-config-predatabackup SUCCESS [8.762742]
Jun  5 13:00:54 mynethserver kernel: duc[1693]: segfault at 1f700000020 ip 00007f6b96021418 sp 00007fff26a9b730 error 4 in libc-2.17.so[7f6b95fa5000+1b8000]
Jun  5 13:00:54 mynethserver esmith::event[1205]: /etc/e-smith/events/pre-backup-data/S20nethserver-restore-data-duc-index: line 47:  1693 Segmentation fault      /usr/bin/duc index $INDEX_DIR --database=$DB_FILE

But I do not think it’s the memory, since my server has got 64Gb RAM. Ok 22Gb is used by KVM but still aught to be enough, no?