Koozali.org: home of the SME Server
Contribs.org Forums => General Discussion => Topic started by: HE on October 26, 2018, 06:20:54 PM
-
Hello I have been getting this error lately and would appreciate any knowledge of what caused it and how to fix on my SME 9 server running emails and staff share nothing fancy
Backup terminated: pre-backup failed - status: 256
-
Can you first tell us a bit more about your server and how you run your backups.
Can you also have a look at /var/log/mesages and see what else you can see
-
Hello Thanks for the reply it backs up to a NAS using workstation backup how much of the message logs would you like to see
Here is part of today with what I assume are hardware issues
Oct 21 03:28:03 server rsyslogd: [origin software="rsyslogd" swVersion="5.8.10" x-pid="1144" x-info="http://www.rsyslog.com"] rsyslogd was HUPed
Oct 21 03:47:49 server dhcpd: DHCPREQUEST for 172.16.20.230 from d0:50:99:a2:b6:82 (ww) via eth3
Oct 21 03:47:49 server dhcpd: DHCPACK on 172.16.20.230 to d0:50:99:a2:b6:82 (ww) via eth3
Oct 21 04:52:02 server dhcpd: Wrote 34 leases to leases file.
Oct 21 04:52:02 server dhcpd: DHCPREQUEST for 172.16.20.249 from c8:3a:35:c1:e1:6b (chat-pc) via eth3
Oct 21 04:52:02 server dhcpd: DHCPACK on 172.16.20.249 to c8:3a:35:c1:e1:6b (chat-pc) via eth3
Oct 21 05:27:26 server dhcpd: DHCPINFORM from 172.16.20.248 via eth3
Oct 21 05:27:26 server dhcpd: DHCPACK to 172.16.20.248 (c8:3a:35:c5:73:71) via eth3
Oct 21 08:18:14 server dhcpd: Wrote 34 leases to leases file.
Oct 21 08:18:14 server dhcpd: DHCPREQUEST for 172.16.20.248 from c8:3a:35:c5:73:71 (sw-PC) via eth3
Oct 21 08:18:14 server dhcpd: DHCPACK on 172.16.20.248 to c8:3a:35:c5:73:71 (sw-PC) via eth3
Oct 21 08:18:29 server dhcpd: DHCPREQUEST for 172.16.20.250 from ac:f1:df:13:6b:97 (cdc-PC) via eth3
Oct 21 08:18:29 server dhcpd: DHCPACK on 172.16.20.250 to ac:f1:df:13:6b:97 (cdc-PC) via eth3
Oct 21 08:33:59 server dhcpd: DHCPREQUEST for 172.16.20.248 from c8:3a:35:c5:73:71 (sw-PC) via eth3
Oct 21 08:33:59 server dhcpd: DHCPACK on 172.16.20.248 to c8:3a:35:c5:73:71 (sw-PC) via eth3
Oct 21 08:34:07 server dhcpd: DHCPREQUEST for 172.16.20.250 from ac:f1:df:13:6b:97 (cdc-PC) via eth3
Oct 21 08:34:07 server dhcpd: DHCPACK on 172.16.20.250 to ac:f1:df:13:6b:97 (cdc-PC) via eth3
Oct 21 09:18:38 server dhcpd: Wrote 34 leases to leases file.
Oct 21 10:40:16 server kernel: imklog 5.8.10, log source = /proc/kmsg started.
Oct 21 10:40:16 server rsyslogd: [origin software="rsyslogd" swVersion="5.8.10" x-pid="1146" x-info="http://www.rsyslog.com"] start
Oct 21 10:40:16 server kernel: Initializing cgroup subsys cpuset
Oct 21 10:40:16 server kernel: Initializing cgroup subsys cpu
Oct 21 10:40:16 server kernel: Linux version 2.6.32-754.3.5.el6.x86_64 (mockbuild@x86-01.bsys.centos.org) (gcc version 4.4.7 20120313 (Red Hat 4.4.7-23) (GCC) ) #1 SMP Tue Aug 14 20:46:41 UTC 2018
Oct 21 10:40:16 server kernel: Command line: ro rd_NO_PLYMOUTH root=/dev/mapper/main-root rd_NO_LUKS rd_MD_UUID=0f146412:bda7216a:d7075ec8:f9ef6aff LANG=en_US.UTF-8 rd_LVM_LV=main/root nodmraid rd_LVM_LV=main/swap SYSFONT=latarcyrheb-sun16 KEYBOARDTYPE=pc KEYTABLE=us rd_NO_DM rhgb quiet crashkernel=auto
Oct 21 10:40:16 server kernel: KERNEL supported cpus:
Oct 21 10:40:16 server kernel: Intel GenuineIntel
Oct 21 10:40:16 server kernel: AMD AuthenticAMD
Oct 21 10:40:16 server kernel: Centaur CentaurHauls
Oct 21 10:40:16 server kernel: BIOS-provided physical RAM map:
Oct 21 10:40:16 server kernel: BIOS-e820: 0000000000000000 - 000000000009d800 (usable)
Oct 21 10:40:16 server kernel: BIOS-e820: 000000000009d800 - 00000000000a0000 (reserved)
Oct 21 10:40:16 server kernel: BIOS-e820: 00000000000e0000 - 0000000000100000 (reserved)
Oct 21 10:40:16 server kernel: BIOS-e820: 0000000000100000 - 00000000c7061000 (usable)
Oct 21 10:40:16 server kernel: BIOS-e820: 00000000c7061000 - 00000000c7068000 (ACPI NVS)
Oct 21 10:40:16 server kernel: BIOS-e820: 00000000c7068000 - 00000000c74ab000 (usable)
Oct 21 10:40:16 server kernel: BIOS-e820: 00000000c74ab000 - 00000000c7a3c000 (reserved)
Oct 21 10:40:16 server kernel: BIOS-e820: 00000000c7a3c000 - 00000000d8dae000 (usable)
Oct 21 10:40:16 server kernel: BIOS-e820: 00000000d8dae000 - 00000000d8e45000 (reserved)
Oct 21 10:40:16 server kernel: BIOS-e820: 00000000d8e45000 - 00000000d8e97000 (usable)
Oct 21 10:40:16 server kernel: BIOS-e820: 00000000d8e97000 - 00000000d8fc8000 (ACPI NVS)
Oct 21 10:40:16 server kernel: BIOS-e820: 00000000d8fc8000 - 00000000d9fff000 (reserved)
Oct 21 10:40:16 server kernel: BIOS-e820: 00000000d9fff000 - 00000000da000000 (usable)
Oct 21 10:40:16 server kernel: BIOS-e820: 00000000db000000 - 00000000df200000 (reserved)
Oct 21 10:40:16 server kernel: BIOS-e820: 00000000f8000000 - 00000000fc000000 (reserved)
Oct 21 10:40:16 server kernel: BIOS-e820: 00000000fec00000 - 00000000fec01000 (reserved)
Oct 21 10:40:16 server kernel: BIOS-e820: 00000000fed00000 - 00000000fed04000 (reserved)
Oct 21 10:40:16 server kernel: BIOS-e820: 00000000fed1c000 - 00000000fed20000 (reserved)
Oct 21 10:40:16 server kernel: BIOS-e820: 00000000fee00000 - 00000000fee01000 (reserved)
Oct 21 10:40:16 server kernel: BIOS-e820: 00000000ff000000 - 0000000100000000 (reserved)
Oct 21 10:40:16 server kernel: BIOS-e820: 0000000100000000 - 000000021fe00000 (usable)
Oct 21 10:40:16 server kernel: SMBIOS version 2.8 @ 0xF04D0
Oct 21 10:40:16 server kernel: SMBIOS 2.8 present.
Oct 21 10:40:16 server kernel: AMI BIOS detected: BIOS may corrupt low RAM, working around it.
Oct 21 10:40:16 server kernel: last_pfn = 0x21fe00 max_arch_pfn = 0x400000000
Oct 21 10:40:16 server kernel: x86 PAT enabled: cpu 0, old 0x7040600070406, new 0x7010600070106
Oct 21 10:40:16 server kernel: total RAM covered: 8110M
Oct 21 10:40:16 server kernel: Found optimal setting for mtrr clean up
Oct 21 10:40:16 server kernel: gran_size: 64K chunk_size: 128M num_reg: 8 lose cover RAM: 0G
Oct 21 10:40:16 server kernel: last_pfn = 0xda000 max_arch_pfn = 0x400000000
Oct 21 10:40:16 server kernel: Using GB pages for direct mapping
Oct 21 10:40:16 server kernel: init_memory_mapping: 0000000000000000-00000000da000000
Oct 21 10:40:16 server kernel: init_memory_mapping: 0000000100000000-000000021fe00000
Oct 21 10:40:16 server kernel: RAMDISK: 36e17000 - 37fefe43
Oct 21 10:40:16 server kernel: ACPI: Deleted _OSI(Windows 2012)
Oct 21 10:40:16 server kernel: ACPI: Deleted _OSI(Windows 2013)
Oct 21 10:40:16 server kernel: ACPI: RSDP 00000000000f04a0 00024 (v02 ALASKA)
Oct 21 10:40:16 server kernel: ACPI: XSDT 00000000d8f9b080 0007C (v01 ALASKA A M I 01072009 AMI 00010013)
Oct 21 10:40:16 server kernel: ACPI: FACP 00000000d8fa8668 0010C (v05 ALASKA A M I 01072009 AMI 00010013)
Oct 21 10:40:16 server kernel: ACPI: DSDT 00000000d8f9b190 0D4D2 (v02 ALASKA A M I 00000036 INTL 20120711)
Oct 21 10:40:16 server kernel: ACPI: FACS 00000000d8fc7f80 00040
Oct 21 10:40:16 server kernel: ACPI: APIC 00000000d8fa8778 00072 (v03 ALASKA A M I 01072009 AMI 00010013)
Oct 21 10:40:16 server kernel: ACPI: FPDT 00000000d8fa87f0 00044 (v01 ALASKA A M I 01072009 AMI 00010013)
Oct 21 10:40:16 server kernel: ACPI: ASF! 00000000d8fa8838 000A5 (v32 INTEL HCG 00000001 TFSM 000F4240)
Oct 21 10:40:16 server kernel: ACPI: SSDT 00000000d8fa88e0 00539 (v01 PmRef Cpu0Ist 00003000 INTL 20120711)
Oct 21 10:40:16 server kernel: ACPI: SSDT 00000000d8fa8e20 00AD8 (v01 PmRef CpuPm 00003000 INTL 20120711)
Oct 21 10:40:16 server kernel: ACPI: MCFG 00000000d8fa98f8 0003C (v01 ALASKA A M I 01072009 MSFT 00000097)
Oct 21 10:40:16 server kernel: ACPI: HPET 00000000d8fa9938 00038 (v01 ALASKA A M I 01072009 AMI. 00000005)
Oct 21 10:40:16 server kernel: ACPI: SSDT 00000000d8fa9970 0036D (v01 SataRe SataTabl 00001000 INTL 20120711)
Oct 21 10:40:16 server kernel: ACPI: SSDT 00000000d8fa9ce0 03528 (v01 SaSsdt SaSsdt 00003000 INTL 20091112)
Oct 21 10:40:16 server kernel: ACPI: SSDT 00000000d8fad208 00A26 (v01 Intel_ IsctTabl 00001000 INTL 20120711)
Oct 21 10:40:16 server kernel: Setting APIC routing to flat.
Oct 21 10:40:16 server kernel: No NUMA configuration found
Oct 21 10:40:16 server kernel: Faking a node at 0000000000000000-000000021fe00000
Oct 21 10:40:16 server kernel: Bootmem setup node 0 0000000000000000-000000021fe00000
Oct 21 10:40:16 server kernel: NODE_DATA [0000000000012000 - 0000000000045fff]
Oct 21 10:40:16 server kernel: bootmap [0000000000046000 - 0000000000089fbf] pages 44
Oct 21 10:40:16 server kernel: (8 early reservations) ==> bootmem [0000000000 - 021fe00000]
Oct 21 10:40:16 server kernel: #0 [0000000000 - 0000001000] BIOS data page ==> [0000000000 - 0000001000]
Oct 21 10:40:16 server kernel: #1 [0000006000 - 0000008000] TRAMPOLINE ==> [0000006000 - 0000008000]
Oct 21 10:40:16 server kernel: #2 [0001000000 - 0002052a64] TEXT DATA BSS ==> [0001000000 - 0002052a64]
Oct 21 10:40:16 server kernel: #3 [0036e17000 - 0037fefe43] RAMDISK ==> [0036e17000 - 0037fefe43]
Oct 21 10:40:16 server kernel: #4 [000009d800 - 0000100000] BIOS reserved ==> [000009d800 - 0000100000]
Oct 21 10:40:16 server kernel: #5 [0002053000 - 000205338f] BRK ==> [0002053000 - 000205338f]
Oct 21 10:40:16 server kernel: #6 [0000010000 - 0000011000] PGTABLE ==> [0000010000 - 0000011000]
Oct 21 10:40:16 server kernel: #7 [0000011000 - 0000012000] PGTABLE ==> [0000011000 - 0000012000]
Oct 21 10:40:16 server kernel: found SMP MP-table at [ffff8800000fd7a0] fd7a0
Oct 21 10:40:16 server kernel: Found 129MB of memory at 48MB for crashkernel auto
Oct 21 10:40:16 server kernel: Reserving 129MB of memory at 48MB for crashkernel (System RAM: 8702MB)
Oct 21 10:40:16 server kernel: Zone PFN ranges:
Oct 21 10:40:16 server kernel: DMA 0x00000010 -> 0x00001000
Oct 21 10:40:16 server kernel: DMA32 0x00001000 -> 0x00100000
Oct 21 10:40:16 server kernel: Normal 0x00100000 -> 0x0021fe00
Oct 21 10:40:16 server kernel: Movable zone start PFN for each node
Oct 21 10:40:16 server kernel: early_node_map[7] active PFN ranges
Oct 21 10:40:16 server kernel: 0: 0x00000010 -> 0x0000009d
Oct 21 10:40:16 server kernel: 0: 0x00000100 -> 0x000c7061
Oct 21 10:40:16 server kernel: 0: 0x000c7068 -> 0x000c74ab
Oct 21 10:40:16 server kernel: 0: 0x000c7a3c -> 0x000d8dae
Oct 21 10:40:16 server kernel: 0: 0x000d8e45 -> 0x000d8e97
Oct 21 10:40:16 server kernel: 0: 0x000d9fff -> 0x000da000
Oct 21 10:40:16 server kernel: 0: 0x00100000 -> 0x0021fe00
Oct 21 10:40:16 server kernel: Reserving Intel graphics stolen memory at 0xdb200000-0xdf1fffff
Oct 21 10:40:16 server kernel: ACPI: PM-Timer IO Port: 0x1808
Oct 21 10:40:16 server kernel: Setting APIC routing to flat.
Oct 21 10:40:16 server kernel: ACPI: LAPIC (acpi_id[0x01] lapic_id[0x00] enabled)
Oct 21 10:40:16 server kernel: ACPI: LAPIC (acpi_id[0x02] lapic_id[0x02] enabled)
Oct 21 10:40:16 server kernel: ACPI: LAPIC (acpi_id[0x03] lapic_id[0x01] enabled)
Oct 21 10:40:16 server kernel: ACPI: LAPIC (acpi_id[0x04] lapic_id[0x03] enabled)
Oct 21 10:40:16 server kernel: ACPI: LAPIC_NMI (acpi_id[0xff] high edge lint[0x1])
Oct 21 10:40:16 server kernel: ACPI: IOAPIC (id[0x08] address[0xfec00000] gsi_base[0])
Oct 21 10:40:16 server kernel: IOAPIC[0]: apic_id 8, version 32, address 0xfec00000, GSI 0-23
Oct 21 10:40:16 server kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
Oct 21 10:40:16 server kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
Oct 21 10:40:16 server kernel: Using ACPI (MADT) for SMP configuration information
Oct 21 10:40:16 server kernel: ACPI: HPET id: 0x8086a701 base: 0xfed00000
Oct 21 10:40:16 server kernel: SMP: Allowing 4 CPUs, 0 hotplug CPUs
Oct 21 10:40:16 server kernel: PM: Registered nosave memory: 000000000009d000 - 000000000009e000
Oct 21 10:40:16 server kernel: PM: Registered nosave memory: 000000000009e000 - 00000000000a0000
Oct 21 10:40:16 server kernel: PM: Registered nosave memory: 00000000000a0000 - 00000000000e0000
Oct 21 10:40:16 server kernel: PM: Registered nosave memory: 00000000000e0000 - 0000000000100000
Oct 21 10:40:16 server kernel: PM: Registered nosave memory: 00000000c7061000 - 00000000c7068000
Oct 21 10:40:16 server kernel: PM: Registered nosave memory: 00000000c74ab000 - 00000000c7a3c000
Oct 21 10:40:16 server kernel: PM: Registered nosave memory: 00000000d8dae000 - 00000000d8e45000
Oct 21 10:40:16 server kernel: PM: Registered nosave memory: 00000000d8e97000 - 00000000d8fc8000
Oct 21 10:40:16 server kernel: PM: Registered nosave memory: 00000000d8fc8000 - 00000000d9fff000
Oct 21 10:40:16 server kernel: PM: Registered nosave memory: 00000000da000000 - 00000000db000000
Oct 21 10:40:16 server kernel: PM: Registered nosave memory: 00000000db000000 - 00000000df200000
Oct 21 10:40:16 server kernel: PM: Registered nosave memory: 00000000df200000 - 00000000f8000000
Oct 21 10:40:16 server kernel: PM: Registered nosave memory: 00000000f8000000 - 00000000fc000000
Oct 21 10:40:16 server kernel: PM: Registered nosave memory: 00000000fc000000 - 00000000fec00000
Oct 21 10:40:16 server kernel: PM: Registered nosave memory: 00000000fec00000 - 00000000fec01000
Oct 21 10:40:16 server kernel: PM: Registered nosave memory: 00000000fec01000 - 00000000fed00000
Oct 21 10:40:16 server kernel: PM: Registered nosave memory: 00000000fed00000 - 00000000fed04000
Oct 21 10:40:16 server kernel: PM: Registered nosave memory: 00000000fed04000 - 00000000fed1c000
Oct 21 10:40:16 server kernel: PM: Registered nosave memory: 00000000fed1c000 - 00000000fed20000
Oct 21 10:40:16 server kernel: PM: Registered nosave memory: 00000000fed20000 - 00000000fee00000
Oct 21 10:40:16 server kernel: PM: Registered nosave memory: 00000000fee00000 - 00000000fee01000
Oct 21 10:40:16 server kernel: PM: Registered nosave memory: 00000000fee01000 - 00000000ff000000
Oct 21 10:40:16 server kernel: PM: Registered nosave memory: 00000000ff000000 - 0000000100000000
-
Your log doesn't tell us much part from it looks like your server stopped/rebooted around:
Oct 21 10:40:16 server kernel: imklog 5.8.10, log source = /proc/kmsg started.
Doesn't look like there was any shutdown or reboot command? Have you got a server hardware issue?
On top of that there is nothing in that log extract about your backup.
You need to go find the the events in your logs where it starts the backup.
Try looking for this
grep -i backup /var/log/messages*
That should find you the events - you are looking for something along the lines of:
esmith esmith::event[8505]: Processing event: pre-backup......
You can then follow along and find out what it reports - don't paste huge screeds of logs here - either do it selectively, or use a gist or pastebin etc
You still haven't told us about your server, backup media, backup method etc etc, so without that lot we can't really tell you much.
You can get a lot of information from your server-manage under 'Report a bug', Create Configuration report.
-
Also note if you had searched the forums for your error you would have found this sage piece of advice....
https://forums.contribs.org/index.php/topic,49108.msg244898.html#msg244898
I suggest you search for say:
status: 256
And read some of the responses
-
Hello
Here are the logs for the days the backup was initiated and meant to end on friday night and sat morning at the latest
/var/log/messages.20181015011201:Oct 19 13:21:38 servernameserver /etc/e-smith/web/panels/manager/cgi bin/backup[3101]: /home/e-smith/db/configuration: OLD backupwk=service|BackupTime|22:00|Compression|6|CompressionProg|gzip|DaysInSet|1|FullDay|2|IncNum|1|IncOnlyTimeout|yes|Login|admin|Mount|/mnt/smb|Password|password|Program|dar|SetNum|1|SetsMax|1|SmbHost|192.168.0.1|SmbShare|backup|Timeout|8|VFSType|cifs|status|enabled
/var/log/messages.20181015011201:Oct 19 13:21:38 servernameserver /etc/e-smith/web/panels/manager/cgi-bin/backup[3101]: /home/e-smith/db/configuration: NEW backupwk=service|BackupTime|22:00|Compression|6|CompressionProg|gzip|DaysInSet|1|FullDay|5|IncNum|1|IncOnlyTimeout|yes|Login|admin|Mount|/mnt/smb|Password|password|Program|dar|SetNum|1|SetsMax|1|SmbHost|192.168.0.1|SmbShare|backup|Timeout|8|VFSType|cifs|status|enabled
/var/log/messages.20181015011201:Oct 19 13:21:38 servernameserver esmith::event[3102]: Processing event: conf-backup
/var/log/messages.20181015011201:Oct 19 13:21:38 servernameserver esmith::event[3102]: expanding /etc/flexbackup.conf
/var/log/messages.20181015011201:Oct 19 13:21:38 servernameserver esmith::event[3102]: generic_template_expand=action|Event|conf-backup|Action|generic_template_expand|Start|1539948098 826530|End|1539948098 980345|Elapsed|0.153815
/var/log/messages.20181015011201:Oct 19 22:00:01 servernameserver /sbin/e-smith/do_backupwk[2979]: /home/e-smith/db/backups: OLD 1539979201=(undefined)
/var/log/messages.20181015011201:Oct 19 22:00:01 servernameserver /sbin/e-smith/do_backupwk[2979]: /home/e-smith/db/backups: NEW 1539979201=backup_record
/var/log/messages.20181015011201:Oct 19 22:00:01 servernameserver /sbin/e-smith/do_backupwk[2979]: /home/e-smith/db/backups: OLD 1539979201=backup_record
/var/log/messages.20181015011201:Oct 19 22:00:01 servernameserver /sbin/e-smith/do_backupwk[2979]: /home/e-smith/db/backups: NEW 1539979201=backup_record|StartEpochTime|1539979201
/var/log/messages.20181015011201:Oct 19 22:00:01 servernameserver /sbin/e-smith/do_backupwk[2979]: /home/e-smith/db/backups: OLD 1539979201=backup_record|StartEpochTime|1539979201
/var/log/messages.20181015011201:Oct 19 22:00:01 servernameserver /sbin/e-smith/do_backupwk[2979]: /home/e-smith/db/backups: NEW 1539979201=backup_record|BackupType|workstation|StartEpochTime|1539979201
/var/log/messages.20181015011201:Oct 19 22:00:01 servernameserver esmith::event[2980]: Processing event: pre-backup
/var/log/messages.20181015011201:Oct 19 22:00:01 servernameserver esmith::event[2980]: expanding /etc/dar/DailyBackup.dcf
/var/log/messages.20181015011201:Oct 19 22:00:02 servernameserver esmith::event[2980]: generic_template_expand=action|Event|pre-backup|Action|generic_template_expand|Start|1539979201 887312|End|1539979202 186747|Elapsed|0.299435
/var/log/messages.20181015011201:Oct 19 22:00:02 servernameserver esmith::event[2980]: Running event handler: /etc/e-smith/events/pre-backup/S10mysql-delete-dumped-tables
/var/log/messages.20181015011201:Oct 19 22:00:02 servernameserver esmith::event[2980]: S10mysql-delete-dumped-tables=action|Event|pre-backup|Action|S10mysql-delete-dumped-tables|Start|1539979202 186951|End|1539979202 208153|Elapsed|0.021202
/var/log/messages.20181015011201:Oct 19 22:00:02 servernameserver esmith::event[2980]: Running event handler: /etc/e-smith/events/pre-backup/S20mysql-dump-tables
/var/log/messages.20181015011201:Oct 19 22:00:03 servernameserver esmith::event[2980]: S20mysql-dump-tables=action|Event|pre-backup|Action|S20mysql-dump-tables|Start|1539979202 208368|End|1539979203 18616|Elapsed|0.810248|Status|256
/var/log/messages.20181015011201:Oct 19 22:00:03 servernameserver esmith::event[2980]: Running event handler: /etc/e-smith/events/pre-backup/S30ldap-dump
/var/log/messages.20181015011201:Oct 19 22:00:03 servernameserver esmith::event[2980]: S30ldap-dump=action|Event|pre-backup|Action|S30ldap-dump|Start|1539979203 18768|End|1539979203 174217|Elapsed|0.155449
/var/log/messages.20181015011201:Oct 19 22:00:03 servernameserver esmith::event[2980]: Running event handler: /etc/e-smith/events/pre-backup/S50rewind-tape
/var/log/messages.20181015011201:Oct 19 22:00:03 servernameserver esmith::event[2980]: S50rewind-tape=action|Event|pre-backup|Action|S50rewind-tape|Start|1539979203 174644|End|1539979203 217193|Elapsed|0.042549
/var/log/messages.20181015011201:Oct 19 22:00:03 servernameserver /sbin/e-smith/do_backupwk[2979]: /home/e-smith/db/backups: OLD 1539979201=backup_record|BackupType|workstation|StartEpochTime|1539979201
/var/log/messages.20181015011201:Oct 19 22:00:03 servernameserver /sbin/e-smith/do_backupwk[2979]: /home/e-smith/db/backups: NEW 1539979201=backup_record|BackupType|workstation|EndEpochTime|1539979203|StartEpochTime|1539979201
/var/log/messages.20181015011201:Oct 19 22:00:03 servernameserver /sbin/e-smith/do_backupwk[2979]: /home/e-smith/db/backups: OLD 1539979201=backup_record|BackupType|workstation|EndEpochTime|1539979203|StartEpochTime|1539979201
/var/log/messages.20181015011201:Oct 19 22:00:03 servernameserver /sbin/e-smith/do_backupwk[2979]: /home/e-smith/db/backups: NEW 1539979201=backup_record|BackupType|workstation|EndEpochTime|1539979203|Result|pre-backup:256|StartEpochTime|1539979201
/var/log/messages.20181015011201:Oct 20 22:00:01 severnameserver /sbin/e-smith/do_backupwk[4275]: /home/e-smith/db/backups: OLD 1540065601=(undefined)
/var/log/messages.20181015011201:Oct 20 22:00:01 severnameserver /sbin/e-smith/do_backupwk[4275]: /home/e-smith/db/backups: NEW 1540065601=backup_record
/var/log/messages.20181015011201:Oct 20 22:00:01 severnameserver /sbin/e-smith/do_backupwk[4275]: /home/e-smith/db/backups: OLD 1540065601=backup_record
/var/log/messages.20181015011201:Oct 20 22:00:01 severnameserver /sbin/e-smith/do_backupwk[4275]: /home/e-smith/db/backups: NEW 1540065601=backup_record|StartEpochTime|1540065601
/var/log/messages.20181015011201:Oct 20 22:00:01 severnameserver /sbin/e-smith/do_backupwk[4275]: /home/e-smith/db/backups: OLD 1540065601=backup_record|StartEpochTime|1540065601
/var/log/messages.20181015011201:Oct 20 22:00:01 severnameserver /sbin/e-smith/do_backupwk[4275]: /home/e-smith/db/backups: NEW 1540065601=backup_record|BackupType|workstation|StartEpochTime|1540065601
/var/log/messages.20181015011201:Oct 20 22:00:01 severnameserver esmith::event[4276]: Processing event: pre-backup
/var/log/messages.20181015011201:Oct 20 22:00:02 severnameserver esmith::event[4276]: expanding /etc/dar/DailyBackup.dcf
/var/log/messages.20181015011201:Oct 20 22:00:02 severnameserver esmith::event[4276]: generic_template_expand=action|Event|pre-backup|Action|generic_template_expand|Start|1540065601 991231|End|1540065602 281327|Elapsed|0.290096
/var/log/messages.20181015011201:Oct 20 22:00:02 severnameserver esmith::event[4276]: Running event handler: /etc/e-smith/events/pre-backup/S10mysql-delete-dumped-tables
/var/log/messages.20181015011201:Oct 20 22:00:02 severnameserver esmith::event[4276]: S10mysql-delete-dumped-tables=action|Event|pre-backup|Action|S10mysql-delete-dumped-tables|Start|1540065602 281531|End|1540065602 287725|Elapsed|0.006194
/var/log/messages.20181015011201:Oct 20 22:00:02 severnameserver esmith::event[4276]: Running event handler: /etc/e-smith/events/pre-backup/S20mysql-dump-tables
/var/log/messages.20181015011201:Oct 20 22:00:03 severnameserver esmith::event[4276]: S20mysql-dump-tables=action|Event|pre-backup|Action|S20mysql-dump-tables|Start|1540065602 287936|End|1540065603 83067|Elapsed|0.795131|Status|256
/var/log/messages.20181015011201:Oct 20 22:00:03 severnameserver esmith::event[4276]: Running event handler: /etc/e-smith/events/pre-backup/S30ldap-dump
/var/log/messages.20181015011201:Oct 20 22:00:03 severnameserver esmith::event[4276]: S30ldap-dump=action|Event|pre-backup|Action|S30ldap-dump|Start|1540065603 83224|End|1540065603 153564|Elapsed|0.07034
/var/log/messages.20181015011201:Oct 20 22:00:03 severnameserver esmith::event[4276]: Running event handler: /etc/e-smith/events/pre-backup/S50rewind-tape
/var/log/messages.20181015011201:Oct 20 22:00:03 severnameserver esmith::event[4276]: S50rewind-tape=action|Event|pre-backup|Action|S50rewind-tape|Start|1540065603 153753|End|1540065603 191353|Elapsed|0.0376
/var/log/messages.20181015011201:Oct 20 22:00:03 severnameserver /sbin/e-smith/do_backupwk[4275]: /home/e-smith/db/backups: OLD 1540065601=backup_record|BackupType|workstation|StartEpochTime|1540065601
/var/log/messages.20181015011201:Oct 20 22:00:03 severnameserver /sbin/e-smith/do_backupwk[4275]: /home/e-smith/db/backups: NEW 1540065601=backup_record|BackupType|workstation|EndEpochTime|1540065603|StartEpochTime|1540065601
/var/log/messages.20181015011201:Oct 20 22:00:03 severnameserver /sbin/e-smith/do_backupwk[4275]: /home/e-smith/db/backups: OLD 1540065601=backup_record|BackupType|workstation|EndEpochTime|1540065603|StartEpochTime|1540065601
/var/log/messages.20181015011201:Oct 20 22:00:03 severnameserver /sbin/e-smith/do_backupwk[4275]: /home/e-smith/db/backups: NEW 1540065601=backup_record|BackupType|workstation|EndEpochTime|1540065603|Result|pre-backup:256|StartEpochTime|1540065601
-
Run this from the cli: db configuration show backupwk and post results here.
At least it will show us what your backup config is..
From the log bits you have shown you have backup set to do a backup on day 5 at 22:00, a full and with one incremental
The bits you have shown do not show a post-backup event,
How big is the backup?
-
Wondering if the error comes from this:
/var/log/messages.20181015011201:Oct 19 22:00:03 servernameserver esmith::event[2980]: S20mysql-dump-tables=action|Event|pre-backup|Action|S20mysql-dump-tables|Start|1539979202 208368|End|1539979203 18616|Elapsed|0.810248|Status|256
Any idea what it should be Terry?
-
Hello
The backup is about 300GB
BackupTime=22:00
Compression=6
CompressionProg=gzip
DaysInSet=1
FullDay=5
IncNum=1
IncOnlyTimeout=yes
Login=admin
Mount=/mnt/smb
Password=password
Program=dar
SetNum=1
SetsMax=1
SmbHost=192.168.0.1
SmbShare=backup
Timeout=8
VFSType=cifs
status=enabled
-
Wondering if the error comes from this:
/var/log/messages.20181015011201:Oct 19 22:00:03 servernameserver esmith::event[2980]: S20mysql-dump-tables=action|Event|pre-backup|Action|S20mysql-dump-tables|Start|1539979202 208368|End|1539979203 18616|Elapsed|0.810248|Status|256
Any idea what it should be Terry?
Possibly a corrupt db thats preventing the mysql-dump-tables from completing.
what happens if you run :
/etc/e-smith/events/actions/mysql-dump-tables
Look in /home/e-smith/db/mysql/ to see if the databases are dumped.
Check the databases are ok with :
mysqlcheck -c --all-databases
and if needed repair :
mysqlcheck -r --all-databases
-
To quick for me warren :-)
Does this run OK:
# mysqldump -v --single-transaction --add-drop-table -QB information_schema -r /home/e-smith/db/mysql/information_schema.dump
-
Any idea what it should be Terry?
Corrupt/Locked table?
Dunno, all will be revealed in the fullness of time.. :-)
-
Possibly a corrupt db thats preventing the mysql-dump-tables from completing.
what happens if you run :
/etc/e-smith/events/actions/mysql-dump-tables
Look in /home/e-smith/db/mysql/ to see if the databases are dumped.
Check the databases are ok with :
mysqlcheck -c --all-databases
and if needed repair :
mysqlcheck -r --all-databases
This is the result
mysqldump: Couldn't execute 'show create table `bd_tx_log`': Table './bandwidthd/bd_tx_log' is marked as crashed and should be repaired (145)
-
After running mysqlcheck -c --all-databases
/etc/e-smith/events/actions/mysql-dump-tables
mysqldump: Couldn't execute 'show create table `bd_tx_log`': Table './bandwidthd/bd_tx_log' is marked as crashed and should be repaired (145)
[root@server ~]# ^C
[root@server ~]# mysqlcheck -c --all-databases
bandwidthd.bd_rx_log OK
bandwidthd.bd_rx_total_log
warning : 3 clients are using or haven't closed the table properly
status : OK
bandwidthd.bd_tx_log
warning : Table is marked as crashed
warning : 3 clients are using or haven't closed the table properly
error : Can't read key from filepos: 294912
Error : Incorrect key file for table './bandwidthd/bd_tx_log.MYI'; try to repair it
error : Corrupt
bandwidthd.bd_tx_total_log
warning : 3 clients are using or haven't closed the table properly
status : OK
bandwidthd.sensors
warning : 3 clients are using or haven't closed the table properly
status : OK
horde.horde_alarms OK
horde.horde_cache OK
horde.horde_datatree OK
horde.horde_datatree_attributes OK
horde.horde_groups OK
horde.horde_groups_members OK
horde.horde_histories
warning : 1 client is using or hasn't closed the table properly
status : OK
horde.horde_histories_seq
warning : 1 client is using or hasn't closed the table properly
status : OK
horde.horde_locks OK
horde.horde_perms OK
horde.horde_prefs
warning : 5 clients are using or haven't closed the table properly
status : OK
horde.horde_sessionhandler OK
horde.horde_signups OK
horde.horde_syncml_anchors OK
horde.horde_syncml_map OK
horde.horde_tokens OK
horde.horde_users OK
horde.horde_vfs OK
horde.imp_sentmail OK
horde.ingo_forwards OK
horde.ingo_lists OK
horde.ingo_rules OK
horde.ingo_shares OK
horde.ingo_shares_groups OK
horde.ingo_shares_users OK
horde.ingo_spam OK
horde.ingo_vacations OK
horde.turba_objects OK
horde.turba_shares OK
horde.turba_shares_groups OK
horde.turba_shares_users OK
mysql.columns_priv OK
mysql.db
warning : 6 clients are using or haven't closed the table properly
status : OK
mysql.event OK
mysql.func OK
mysql.general_log
Error : You can't use locks with log tables.
status : OK
mysql.help_category OK
mysql.help_keyword OK
mysql.help_relation OK
mysql.help_topic OK
mysql.host OK
mysql.ndb_binlog_index OK
mysql.plugin OK
mysql.proc OK
mysql.procs_priv OK
mysql.servers OK
mysql.slow_log
Error : You can't use locks with log tables.
status : OK
mysql.tables_priv OK
mysql.time_zone OK
mysql.time_zone_leap_second OK
mysql.time_zone_name OK
mysql.time_zone_transition OK
mysql.time_zone_transition_type OK
mysql.user
warning : 6 clients are using or haven't closed the table properly
status : OK
-
And after running mysqlcheck -r --all-databases
mysqlcheck -r --all-databases
bandwidthd.bd_rx_log OK
bandwidthd.bd_rx_total_log OK
bandwidthd.bd_tx_log OK
bandwidthd.bd_tx_total_log OK
bandwidthd.sensors OK
horde.horde_alarms OK
horde.horde_cache OK
horde.horde_datatree OK
horde.horde_datatree_attributes OK
horde.horde_groups OK
horde.horde_groups_members OK
horde.horde_histories OK
horde.horde_histories_seq OK
horde.horde_locks OK
horde.horde_perms OK
horde.horde_prefs OK
horde.horde_sessionhandler OK
horde.horde_signups OK
horde.horde_syncml_anchors OK
horde.horde_syncml_map OK
horde.horde_tokens OK
horde.horde_users OK
horde.horde_vfs OK
horde.imp_sentmail OK
horde.ingo_forwards OK
horde.ingo_lists OK
horde.ingo_rules OK
horde.ingo_shares OK
horde.ingo_shares_groups OK
horde.ingo_shares_users OK
horde.ingo_spam OK
horde.ingo_vacations OK
horde.turba_objects OK
horde.turba_shares OK
horde.turba_shares_groups OK
horde.turba_shares_users OK
mysql.columns_priv OK
mysql.db OK
mysql.event OK
mysql.func OK
mysql.general_log OK
mysql.help_category OK
mysql.help_keyword OK
mysql.help_relation OK
mysql.help_topic OK
mysql.host OK
mysql.ndb_binlog_index OK
mysql.plugin OK
mysql.proc OK
mysql.procs_priv OK
mysql.servers OK
mysql.slow_log OK
mysql.tables_priv OK
mysql.time_zone OK
mysql.time_zone_leap_second OK
mysql.time_zone_name OK
mysql.time_zone_transition OK
mysql.time_zone_transition_type OK
mysql.user OK
-
After running that I can now use the backup to desktop and it dosnt give me the pre backup error :-)
-
A winner ..
-
Hopefully tonight I can run a full backup.
Will let you know the answer tomorrow thanks for your help!
-
Cool :-)
-
Thank you again for your help it was definitely the fix it has successfully backed up :-) :grin:
Destination disk usage 1.2T, 33% full, 2.5T available
Backup successfully terminated at Thu Nov 1 03:35:18 2018
-
:hammer:
Another issue smashed !!