Backup "Komplettes System" funktioniert nicht mehr

Hallo Community,

seit einiger Zeit bekomme ich in den Logs Fehler auf Grund unseres Backup-Cron-Jobs, welcher täglich um 22:00 Uhr laufen soll.
Hier die Loganzeige im Commander:


2014-04-13 22:00:03	sql: Connecting to database
2014-04-13 22:00:03	tsk020506: Starte Task 020506 'Cronjob ausführen', Parameter: [050302|||--skip-voicemail|--skip-recording|--skip-fax|--skip-log], User-ID: [1]
2014-04-13 22:00:03	Starte Cron Job 050302
2014-04-13 22:00:04	tsk050302: Starte Child-Task 050302 'Systemsicherung durchführen', Parameter: --skip-voicemail|--skip-recording|--skip-fax|--skip-log]
2014-04-13 22:00:04	Datensicherung beginnt
2014-04-13 22:00:04	. Starte [apt-get clean]
2014-04-13 22:00:04	. Exit: [0]
2014-04-13 22:00:04	. Starte [nice -n 19 /sbin/backup.pl --skip-voicemail --skip-recording --skip-fax --skip-log]
2014-04-13 22:09:56	... FATAL - UNKNOWN ERROR
2014-04-13 22:09:56	... FATAL - CANCLE EXIT: unknown_error 255
2014-04-13 22:09:56	. Exit: [255]
2014-04-13 22:09:56	Es trat ein unbekannter Fehler auf!
2014-04-13 22:09:56	Child-Task 050302 wurde mit ] beendet
2014-04-13 22:09:56	tsk020506: CronJob 050302 mit Fehler beendet

Führe ich über Appliance -> Sicherung -> Datenbanksicherung eine manuelle Sicherung der Datenbank durch, funktioniert dies anstandslos. Starte ich hingegen über Appliance -> Sicherung -> Komplettes System eine vollständige Sicherung, stürzen nach kurzer Zeit Dienste wie zum Beispiel die XMPP Schnittstelle ab, man bekommt ein overload und nach einigen Minuten später, stürzt die komplette Anlage ab, sodass ein Telefonieren nicht mehr möglich ist. Was ist hier los?

Version ist 7.06.02.

Beste Grüße
Sebastian

Hallo Sebastian,

verwendest du von uns Unterstützte Hardware? Ist die Anlage virtualisiert? Poste bitte hierzu mal die Ausgabe von “lspci”
hast du irgendwo besonders große Dateien rumliegen oder ist Festplatte der Appliance sehr klein? Poste bitte hier mal die Ausgabe von “df -h”

seit einiger Zeit…

Kannst du eine ungefähre zeitliche Abschätzung geben, seit wann das Problem auftritt?

Grüße,
Jan

Hallo Jan,

ja, die Hardware ist von euch.
Hier der Result von lspci:


root@mobydick:/etc/admin# lspci
00:00.0 Host bridge: Intel Corporation Sandy Bridge DRAM Controller (rev 09)
00:01.0 PCI bridge: Intel Corporation Sandy Bridge PCI Express Root Port (rev 09)
00:06.0 PCI bridge: Intel Corporation Sandy Bridge PCI Express Root Port (rev 09)
00:16.0 Communication controller: Intel Corporation Cougar Point HECI Controller #1 (rev 04)
00:16.1 Communication controller: Intel Corporation Cougar Point HECI Controller #2 (rev 04)
00:1a.0 USB Controller: Intel Corporation Cougar Point USB Enhanced Host Controller #2 (rev 05)
00:1c.0 PCI bridge: Intel Corporation Cougar Point PCI Express Root Port 1 (rev b5)
00:1c.4 PCI bridge: Intel Corporation Cougar Point PCI Express Root Port 5 (rev b5)
00:1c.5 PCI bridge: Intel Corporation Cougar Point PCI Express Root Port 6 (rev b5)
00:1d.0 USB Controller: Intel Corporation Cougar Point USB Enhanced Host Controller #1 (rev 05)
00:1e.0 PCI bridge: Intel Corporation 82801 PCI Bridge (rev a5)
00:1f.0 ISA bridge: Intel Corporation Cougar Point LPC Controller (rev 05)
00:1f.2 IDE interface: Intel Corporation Cougar Point 4 port SATA IDE Controller (rev 05)
00:1f.3 SMBus: Intel Corporation Cougar Point SMBus Controller (rev 05)
00:1f.5 IDE interface: Intel Corporation Cougar Point 2 port SATA IDE Controller (rev 05)
01:00.0 Ethernet controller: Realtek Semiconductor Co., Ltd. RTL8111/8168B PCI Express Gigabit Ethernet controller (rev 02)
02:00.0 RAID bus controller: 3ware Inc 9650SE SATA-II RAID PCIe (rev 01)
04:00.0 Ethernet controller: Intel Corporation 82574L Gigabit Network Connection
05:00.0 Ethernet controller: Intel Corporation 82574L Gigabit Network Connection
06:03.0 VGA compatible controller: Matrox Graphics, Inc. MGA G200eW WPCM450 (rev 0a)

Und hier die Ausgabe von df -h:


root@mobydick:/etc/admin# df -h
Dateisystem           Size  Used Avail Use% Eingehängt auf
tmpfs                 2,0G     0  2,0G   0% /TARGET/RAM/lib/init/rw
udev                   10M  120K  9,9M   2% /dev
tmpfs                 2,0G  4,0K  2,0G   1% /dev/shm
tmpfs                 1,0G  252K  1,0G   1% /SOURCE/RAMDISK
/dev/sda1             3,8G  1,2G  2,5G  31% /SYSTEM
/dev/vg/SHARE         549G  5,2G  516G   1% /SOURCE/SHARE
/dev/vg/BACKUP        914G   11G  858G   2% /BACKUP
/dev/vg/NODE          183G  188M  174G   1% /SOURCE/NODE
/dev/loop0            475M  475M     0 100% /SOURCE/FIRMWARE
/dev/loop1            356K  356K     0 100% /SOURCE/LINKS
unionfs               1,0G  252K  1,0G   1% /TARGET/RAM
unionfs               183G  188M  174G   1% /TARGET/NODE
unionfs               549G  5,2G  516G   1% /TARGET/SHARE

Wenn ich im Commander unter Appliance -> Sicherung -> Komplettes System schaue, habe ich dort die Möglichkeit das letzte Backup herunterzuladen. Dies ist vom 30.03.2014 22:14:18. Am 31.03.2014 (vor 22:00 Uhr) haben wir das Update auf 7.06.01 durchgeführt.

Beste Grüße
Sebastian

Hallo Jan,

kannst du anhand der oben veröffentlichten Auszüge einen Fehler erkennen oder hast ggf. noch einen Ansatz?

Beste Grüße
Sebastian

Hallo Sebastian,

die Details zum Backup stehen in “/var/log/backup.log”.
Schau Dir die Datei mal an oder poste diese ggf. hier im Forum.

Gruß,

Thomas

Hallo Thomas,

er meckert über ein nicht festgelegtes Dateigrößenlimit.
Hier der Auzug von gestern:


2014/04/28 22:00:03 exmsg DEBUG> Locale is de_DE.UTF-8.
2014/04/28 22:00:03 main DEBUG> Reading settings from file /etc/essex/settings.properties
2014/04/28 22:00:03 main DEBUG> LINE: bootmode=harddisk
2014/04/28 22:00:03 main DEBUG> Key: <bootmode> Value: <harddisk>
2014/04/28 22:00:03 main INFO> Bootmode is harddisk
2014/04/28 22:00:05 main INFO> INIT COMPLETE: EXTERNAL BACKUP MEDIA 0 MB, BACKUP FILES 6737 MB, BACKUP PARTITION 935613 MB
2014/04/28 22:00:05 main INFO> Executing: lvcreate -l +50%FREE -s -n NODE_SNAP /dev/vg/NODE
2014/04/28 22:00:06 main DEBUG> >] output: --------------------
File descriptor 3 (/TARGET/SHARE/var/zend/log/zem.log) leaked on lvcreate invocation. Parent PID 1002: /usr/bin/perl
File descriptor 4 (/TARGET/NODE/tmp/ZCUDta9Ire (deleted)) leaked on lvcreate invocation. Parent PID 1002: /usr/bin/perl
File descriptor 5 (/TARGET/SHARE/var/zend/log/utils.log) leaked on lvcreate invocation. Parent PID 1002: /usr/bin/perl
File descriptor 7 (socket:[14260922]) leaked on lvcreate invocation. Parent PID 1002: /usr/bin/perl
  Logical volume "NODE_SNAP" created
2014/04/28 22:00:06 main DEBUG> <] output: --------------------
2014/04/28 22:00:06 main INFO> Executing: lvcreate -l +100%FREE -s -n SHARE_SNAP /dev/vg/SHARE
2014/04/28 22:00:10 main DEBUG> >] output: --------------------
File descriptor 3 (/TARGET/SHARE/var/zend/log/zem.log) leaked on lvcreate invocation. Parent PID 1002: /usr/bin/perl
File descriptor 4 (/TARGET/NODE/tmp/ZCUDta9Ire (deleted)) leaked on lvcreate invocation. Parent PID 1002: /usr/bin/perl
File descriptor 5 (/TARGET/SHARE/var/zend/log/utils.log) leaked on lvcreate invocation. Parent PID 1002: /usr/bin/perl
File descriptor 7 (socket:[14260922]) leaked on lvcreate invocation. Parent PID 1002: /usr/bin/perl
  Logical volume "SHARE_SNAP" created
2014/04/28 22:00:10 main DEBUG> <] output: --------------------
2014/04/28 22:00:10 main INFO> Executing: mount /dev/vg/NODE_SNAP /mnt/NODE_SNAP
2014/04/28 22:00:11 main INFO> Executing: mount /dev/vg/SHARE_SNAP /mnt/SHARE_SNAP
2014/04/28 22:00:11 main INFO> Executing: rm -rf /BACKUP/root/*
2014/04/28 22:00:12 main INFO> Executing: ln -s /SYSTEM/* /BACKUP/root
2014/04/28 22:00:12 main INFO> Executing: mount -o remount,rw /SYSTEM
2014/04/28 22:00:12 main INFO> Executing: sed -i -e 's/LiveDisk (.*)/LiveDisk (backup of Mo 28. Apr 22:00:05 CEST 2014)/' /SYSTEM/isolinux.msg 
2014/04/28 22:00:13 main INFO> Executing: sed -i -e 's/bootmode=setup/bootmode=livedisk/' /SYSTEM/isolinux.cfg 
2014/04/28 22:00:13 main INFO> Executing: genisoimage -m etc/udev/rules.d -m var/run -m var/lock -m var/tmp -m var/lib/mysql/ib_logfile* -m var/spool/asterisk/voicemail -m var/log -m var/spool/asterisk/monitor -m var/spool/asterisk/meetme -m var/spool/hylafax/sendq -m var/spool/hylafax/recvq  -R -U -iso-level 4 -o /BACKUP/root/node.iso  /mnt/NODE_SNAP
2014/04/28 22:00:13 main DEBUG> >] output: --------------------
Warning: creating filesystem that does not conform to ISO-9660.
Warning: Creating ISO-9660:1999 (version 2) filesystem.
Warning: ISO-9660 filenames longer than 31 may cause buffer overflows in the OS.
Total translation table size: 0
Total rockridge attributes bytes: 106694
Total directory bytes: 204800
Path table size(bytes): 356
Max brk space used bb000
424 extents written (0 MB)
2014/04/28 22:00:13 main DEBUG> <] output: --------------------
2014/04/28 22:00:13 main INFO> Executing: genisoimage -m etc/udev/rules.d -m var/run -m var/lock -m var/tmp -m var/lib/mysql/ib_logfile* -m var/spool/asterisk/voicemail -m var/log -m var/spool/asterisk/monitor -m var/spool/asterisk/meetme -m var/spool/hylafax/sendq -m var/spool/hylafax/recvq  -R -U -iso-level 4 -o /BACKUP/root/share.iso  /mnt/SHARE_SNAP
2014/04/28 22:11:17 main DEBUG> >] output: --------------------
Warning: creating filesystem that does not conform to ISO-9660.
Warning: Creating ISO-9660:1999 (version 2) filesystem.
Warning: ISO-9660 filenames longer than 31 may cause buffer overflows in the OS.
  0.17% done, estimate finish Mon Apr 28 22:09:59 2014
  0.34% done, estimate finish Mon Apr 28 22:09:58 2014
  (.. gekürzt ..)
 99.74% done, estimate finish Mon Apr 28 22:11:16 2014
 99.92% done, estimate finish Mon Apr 28 22:11:16 2014
Total translation table size: 0
Total rockridge attributes bytes: 1530086
Total directory bytes: 3901440
Path table size(bytes): 15122
Max brk space used e25000
2922474 extents written (5707 MB)
2014/04/28 22:11:17 main DEBUG> <] output: --------------------
2014/04/28 22:11:17 main INFO> Executing: genisoimage -f -L -d -l -allow-lowercase -allow-multidot -o /BACKUP/appliance.iso -b isolinux.bin -c boot.cat -no-emul-boot -boot-load-size 4 -boot-info-table /BACKUP/root
2014/04/28 22:11:18 main DEBUG> >] output: --------------------
Warning: creating filesystem that does not conform to ISO-9660.
Warning: -follow-links does not always work correctly; be careful.
I: -input-charset not specified, using utf-8 (detected in locale settings)
File /BACKUP/root/share.iso is larger than 4GiB-1.
-allow-limited-size was not specified. There is no way do represent this file size. Aborting.
2014/04/28 22:11:18 main DEBUG> <] output: --------------------
2014/04/28 22:11:18 main ERROR> Returned error: 256
2014/04/28 22:11:18 main FATAL> UNKNOWN ERROR
2014/04/28 22:11:18 main INFO> Executing: umount /mnt/NODE_SNAP
2014/04/28 22:11:18 main INFO> Executing: umount /mnt/SHARE_SNAP
2014/04/28 22:11:23 main INFO> Executing: lvremove -f /dev/vg/NODE_SNAP
2014/04/28 22:11:36 main DEBUG> >] output: --------------------
File descriptor 3 (/TARGET/SHARE/var/zend/log/zem.log) leaked on lvremove invocation. Parent PID 1002: /usr/bin/perl
File descriptor 4 (/TARGET/NODE/tmp/ZCUDta9Ire (deleted)) leaked on lvremove invocation. Parent PID 1002: /usr/bin/perl
File descriptor 5 (/TARGET/SHARE/var/zend/log/utils.log) leaked on lvremove invocation. Parent PID 1002: /usr/bin/perl
File descriptor 7 (socket:[14260922]) leaked on lvremove invocation. Parent PID 1002: /usr/bin/perl
  Logical volume "NODE_SNAP" successfully removed
2014/04/28 22:11:36 main DEBUG> <] output: --------------------
2014/04/28 22:11:36 main INFO> Executing: lvremove -f /dev/vg/SHARE_SNAP
2014/04/28 22:11:37 main DEBUG> >] output: --------------------
File descriptor 3 (/TARGET/SHARE/var/zend/log/zem.log) leaked on lvremove invocation. Parent PID 1002: /usr/bin/perl
File descriptor 4 (/TARGET/NODE/tmp/ZCUDta9Ire (deleted)) leaked on lvremove invocation. Parent PID 1002: /usr/bin/perl
File descriptor 5 (/TARGET/SHARE/var/zend/log/utils.log) leaked on lvremove invocation. Parent PID 1002: /usr/bin/perl
File descriptor 7 (socket:[14260922]) leaked on lvremove invocation. Parent PID 1002: /usr/bin/perl
  Logical volume "SHARE_SNAP" successfully removed
2014/04/28 22:11:37 main DEBUG> <] output: --------------------
2014/04/28 22:11:37 main FATAL> CANCLE EXIT: unknown_error 255

Beste Grüße
Sebastian

Hallo Sebastian,

ja, unser “äusseres” ISO wird nach wie vor mit recht konservativen Parametern gebaut um größtmögliche Kompatibilität zu gewährleisten. In Deinem Fall nun ist eines der “inneren” ISO’s über 5GB groß, das klappt so nicht. Kannst Du denn herausfinden was soviel Platz verbraucht? Eine typische Installation hat an der Stelle auch heute noch unter 1 GB. Liegen da vielleicht noch Mitschnitte oder dergleichen herum?

Du solltest insbesondere in /etc/root und /etc/admin sowie /var/spool/asterisk/* nachschauen.

Gruß,

Thomas

Hallo Thomas,

in den drei Verzeichnissen ist nichts Nennenswertes enthalten. Weiter wundert mich die Größe obwohl das System-Backup mit den Parametern “–skip-voicemail|–skip-recording|–skip-fax|–skip-log” gestartet wird.

Vor einiger Zeit wurde durch euch ein erweitertes Logging auf dieser Anlage aktiviert. Kann das der Auslöser sein? Und kann es sein, dass dieses erweiterte Log nicht mit dem Parameter “–skip-log” ausgeschlossen wird?

Beste Grüße
Sebastian

Es lag tatsächlich am “Asterisk-Logger”, welcher in /var/log/asterisk einige große messages-Logs angelegt hatte.

Ich habe das Log-Level mit Hilfe von Thomas wieder auf “notice,warning,error” gesetzt und die alten Log-Dateien entfernt. Anschließend lief das Backup wieder reibungslos.

Beste Grüße
Sebastian

Hallo Sebastian,

kannst du mir bitte hierzu helfen? Ich habe genau das gleiche Problem! Die Festplatte zeigt voll, und ich vermutte genau das Problem mit den Logs. Nun aber weiss ich nicht welche Logs entfernt bzw. gelöscht werden könne und welche nicht! Und wie können diese gelöscht werden! Ich arbeite mit Filezilla und nicht mal download-en geht nicht wegen den Rechten!

Vielen Dank im Voraus.

Hallo artpr,

  • unter Systemeinstellungen folgenden Key anpassen: “sys.asterisk.configure.logger.file.logfiles.messages” auf “notice,warning,error”
  • Telefoniekonfiguration anwenden
  • In der asterisk CLI den Befehl “logger reload” absetzen
  • Alte Logfiles unter “/var/log/asterisk/” entfernen

FTP/SSH-Login mit “root”, dann sollte auch das funktionieren.

Beste Grüße
Sebastian

Hallo sebastian,

vielen Dank für dein Feedback.

Unter “/var/log/asterisk/” sehe ich grosse Daten mit den Namen ‘‘messages.0 bis 4’’ die gesamt etwa 15 GB ausmachen. Diese soll ich löschen einfach so meinst du?

Danke und Grüße,
artpr

Hallo artpr,

im Grunde schon. Wenn du Bedenken hast, hole sie von der Anlage herunter und schiebe sie auf deinen Rechner.

Schönes Wochenende
Sebastian

An die Sache kann ich mich super anschließen.

root@MobyDick01:/SOURCE/SHARE/etc/admin# du -h --max-depth=8 . | sort -n -r
8,0K    ./.ssh
4,0K    ./oradiag_admin/diag/clients/user_admin/host_3062326077_80/sweep
4,0K    ./oradiag_admin/diag/clients/user_admin/host_3062326077_80/stage
4,0K    ./oradiag_admin/diag/clients/user_admin/host_3062326077_80/metadata_pv
4,0K    ./oradiag_admin/diag/clients/user_admin/host_3062326077_80/metadata_dgif
4,0K    ./oradiag_admin/diag/clients/user_admin/host_3062326077_80/metadata
4,0K    ./oradiag_admin/diag/clients/user_admin/host_3062326077_80/lck
4,0K    ./oradiag_admin/diag/clients/user_admin/host_3062326077_80/incpkg
4,0K    ./oradiag_admin/diag/clients/user_admin/host_3062326077_80/incident
4,0K    ./oradiag_admin/diag/clients/user_admin/host_3062326077_80/cdump
3,0G    ./oradiag_admin/diag/clients/user_admin/host_3062326077_80
3,0G    ./oradiag_admin/diag/clients/user_admin
3,0G    ./oradiag_admin/diag/clients
3,0G    ./oradiag_admin/diag
3,0G    ./oradiag_admin
3,0G    .
1,8G    ./oradiag_admin/diag/clients/user_admin/host_3062326077_80/alert
1,3G    ./oradiag_admin/diag/clients/user_admin/host_3062326077_80/trace

inhalt alert

cat ./oradiag_admin/diag/clients/user_admin/host_3062326077_80/alert/log_177.xml

</msg>
<msg time='2015-07-23T05:20:58.077+02:00' org_id='oracle' comp_id='clients'
 type='UNKNOWN' level='16' host_id='MobyDick01'
 host_addr='127.0.0.1'>
 <txt>Directory does not exist for read/write [/usr/lib/log] ]
 </txt>
</msg>
<msg time='2015-07-23T05:20:58.500+02:00' org_id='oracle' comp_id='clients'
 msg_id='dbgriprae_record_alert_errmsg:3723:225853331' type='ERROR' group='ami_comp'
 level='8' host_id='MobyDick01' host_addr='127.0.0.1'>
 <txt>[AutoCreate Relation]: following error encountered and ignored:
DIA-48316: Message 48316 not found; No message file for product=RDBMS, facility=DIA; arguments: [ADR_CONTROL]
DIA-48210: Message 48210 not found; No message file for product=RDBMS, facility=DIA
DIA-48166: Message 48166 not found; No message file for product=RDBMS, facility=DIA; arguments: [/etc/admin/oradiag_admin/diag/clients/user_admin/host_3062326077_80/metadata/ADR_CONTROL.ams] [0]
DIA-48122: Message 48122 not found; No message file for product=RDBMS, facility=DIA; arguments: [/etc/admin/oradiag_admin/diag/clients/user_admin/host_3062326077_80/metadata/ADR_CONTROL.ams] [0]
DIA-27040: Message 27040 not found; No message file for product=RDBMS, facility=DIA
Linux-x86_64 Error: 22: Invalid argument
 </txt>

</msg>

inhalt trace:

root@MobyDick01:/SOURCE/SHARE/etc/admin# tail -f -n 20 ./oradiag_admin/diag/clients/user_admin/host_3062326077_80/trace/sqlnet.log
Linux-x86_64 Error: 22: Invalid argument
Directory does not exist for read/write [/usr/lib/log] ]
Thu Jul 23 17:47:18 2015
[AutoCreate Relation]: following error encountered and ignored:
DIA-48316: Message 48316 not found; No message file for product=RDBMS, facility=DIA; arguments: [ADR_CONTROL]
DIA-48210: Message 48210 not found; No message file for product=RDBMS, facility=DIA
DIA-48166: Message 48166 not found; No message file for product=RDBMS, facility=DIA; arguments: [/etc/admin/oradiag_admin/diag/clients/user_admin/host_3062326077_80/metadata/ADR_CONTROL.ams] [0]
DIA-48122: Message 48122 not found; No message file for product=RDBMS, facility=DIA; arguments: [/etc/admin/oradiag_admin/diag/clients/user_admin/host_3062326077_80/metadata/ADR_CONTROL.ams] [0]
DIA-27040: Message 27040 not found; No message file for product=RDBMS, facility=DIA
Linux-x86_64 Error: 22: Invalid argument
Directory does not exist for read/write [/usr/lib/log] ]
Thu Jul 23 17:47:18 2015
[AutoCreate Relation]: following error encountered and ignored:
DIA-48316: Message 48316 not found; No message file for product=RDBMS, facility=DIA; arguments: [ADR_CONTROL]
DIA-48210: Message 48210 not found; No message file for product=RDBMS, facility=DIA
DIA-48166: Message 48166 not found; No message file for product=RDBMS, facility=DIA; arguments: [/etc/admin/oradiag_admin/diag/clients/user_admin/host_3062326077_80/metadata/ADR_CONTROL.ams] [0]
DIA-48122: Message 48122 not found; No message file for product=RDBMS, facility=DIA; arguments: [/etc/admin/oradiag_admin/diag/clients/user_admin/host_3062326077_80/metadata/ADR_CONTROL.ams] [0]
DIA-27040: Message 27040 not found; No message file for product=RDBMS, facility=DIA
Linux-x86_64 Error: 22: Invalid argument
Directory does not exist for read/write [/usr/lib/log] ]

Somit auch kein Backup für mich, und auch kein Update :frowning:

Kann ich diese “logs” gefahrenlos löschen? Was tun?

Gruß
Max