Empty logs and jobs not working with cron

karpiq · 2018-12-16 09:48:43

Hi,

I'm setting up the XSI Free and have these 2 problems.:
1) The logs are empty:

The job ends with line:
--exec=yes >> "/vmfs/volumes/58468b1e-752c135f-2ab0-1866dae9637a/xsi-dir/var/logs/xsibackup.log"

Currently I have a job running but when I'm checking the log it's empty:
[root@localhost:/vmfs/volumes/58468b1e-752c135f-2ab0-1866dae9637a/xsi-dir] cat var/logs/xsibackup.log

[root@localhost:/vmfs/volumes/58468b1e-752c135f-2ab0-1866dae9637a/xsi-dir] ls -lrt var/logs/
total 0
-rwxrwxrwx 1 root root 0 Dec 15 14:38 xsibackup.log

2)I can launch the job manually, it works fine but when I'm trying to set the cron to launch it, it seems to take no effect but it's hard to diagnose since the log file is empty. So I've found the troubleshooting guide:
The cron is launched only once:
ps -c | grep -v grep | grep 'busybox crond'
9024966 9024966 busybox /usr/lib/vmware/busybox/bin/busybox crond

The cron is able to add the new line to the text file every minute.
I can see in syslog that it is trying to launch my jobs:
cat /var/log/syslog.log | grep jobs
2018-12-15T19:00:01Z crond[33476]: crond: USER root pid 8884948 cmd "/vmfs/volumes/localRaid5/xsi-dir/jobs/001"
2018-12-15T21:00:01Z crond[8898507]: crond: USER root pid 8911274 cmd "/vmfs/volumes/localRaid5/xsi-dir/jobs/001"
2018-12-16T05:00:01Z crond[8898507]: crond: USER root pid 8929142 cmd "/vmfs/volumes/localRaid5/xsi-dir/jobs/002"
2018-12-16T07:52:01Z crond[8898507]: crond: USER root pid 8935629 cmd "/vmfs/volumes/localRaid5/xsi-dir/jobs/001"
2018-12-16T08:06:01Z crond[8898507]: crond: USER root pid 8936592 cmd "/vmfs/volumes/localRaid5/xsi-dir/jobs/001"
2018-12-16T08:16:01Z crond[8898507]: crond: USER root pid 8937244 cmd "/vmfs/volumes/58468b1e-752c135f-2ab0-1866dae9637a/xsi-dir/jobs/002"

And this is my job:
# This is a backup job file example. It starts with the path to your
# xsibackup file and ends with the redirection to the log file. Please
# do make sure that you keep first and last lines, changing paths to
# match your working environment.

#CPLSV006169

"/vmfs/volumes/58468b1e-752c135f-2ab0-1866dae9637a/xsi-dir/xsibackup" \
--backup-prog=XSITools:z \
--certify-backup=yes \
--backup-point=/vmfs/volumes/b4416a2c-bb0c56fc/backup/ \
--backup-type=Running \
--backup-how=Hot \
--backup-vms=CPLSV006169 \
--remote-xsipath=/vmfs/volumes/58468b1e-752c135f-2ab0-1866dae9637a/xsi-dir \
--backup-id=001 \
--description="XSITools backup of CPLSV006169 FLEXNET" \
--on-success="backupId->006" \
--on-error="backupId->006" \
--snapshot=doquiesce
--backup-room=1600
--date-dir=yes
--exec=yes >> "/vmfs/volumes/58468b1e-752c135f-2ab0-1866dae9637a/xsi-dir/var/logs/xsibackup.log"

So I'd like to get any suggestions what could be wrong
Thanks for help in advance

admin · 2018-12-16 15:20:13

Do not use physical paths for your backups, but the hardlinked paths, i.e.: [b]/vmfs/volumes/localRaid5[/b] instead of [b]/vmfs/volumes/58468b1e-752c135f-2ab0-1866dae9637a[/b]

If your cron daemon is working, you can run your jobs manually but the jobs are not triggered, then, you have some wrong path, or you have not published the crontab changes.

Have you run the [b]./xsibackup --update-cron[/b] command after populating the [b]conf/root-crontab[/b] file?

You could also be using some wrong syntax in the crontab, post the contents of the crontab.

karpiq · 2018-12-17 09:35:10

Ok, I've replaced the physical paths with the hardlinks:

"/vmfs/volumes/localRaid5/xsi-dir/xsibackup" \
--backup-prog=XSITools:z \
--certify-backup=yes \
--backup-point=/vmfs/volumes/Synology-SOS/backup/ \
--backup-type=Running \
--backup-how=Hot \
--backup-vms="CPLSV006169,CPLSVSOS-DHPSFS" \
--remote-xsipath=/vmfs/volumes/localRaid5/xsi-dir \
--backup-id=001 \
--description="XSITools backup" \
--snapshot=doquiesce
--backup-room=1600
--date-dir=yes
--exec=yes >> "/vmfs/volumes/localRaid5/xsi-dir/var/logs/xsibackup.log"

root-crontab looks like this:
# This crontab belongs to the root user, thus it starts by root-
# Add cron jobs to this file in the classic crond Linux way.
# This is an example of a backup job being run everyday at 2:00 a.m.
# change according to your needs and run ./xsibackup --update-cron
# min hour day mon dow command
20 9 * * * /vmfs/volumes/localRaid5/xsi-dir/jobs/001

the cron tried to start the job:
2018-12-17T09:20:01Z crond[9110618]: crond: USER root pid 9110772 cmd /vmfs/volumes/localRaid5/xsi-dir/jobs/001

log file is still empty:
[root@localhost:/vmfs/volumes/58468b1e-752c135f-2ab0-1866dae9637a/xsi-dir] cat v
ar/logs/xsibackup.log
[root@localhost:/vmfs/volumes/58468b1e-752c135f-2ab0-1866dae9637a/xsi-dir]

[root@localhost:/vmfs/volumes/58468b1e-752c135f-2ab0-1866dae9637a/xsi-dir] ls -l
a var/logs/
total 16
drwxr-xr-x 1 root root 420 Dec 15 14:38 .
drwxr-xr-x 1 root root 420 Dec 15 14:38 ..
-rwxrwxrwx 1 root root 0 Dec 15 14:38 xsibackup.log

Any idea why?

Also there is no new backup data but without logs it's hard to say anything:
[root@localhost:~] ls /vmfs/volumes/Synology-SOS/backup/
20181216081843 data

I also launched the job manually:
Blocksize is 52428800 bytes
-------------------------------------------------------------------------------
Compression has been set
Backing up via XSITools
-------------------------------------------------------------------------------
File name: CPLSV006169-flat.vmdk, File size: 107374182400
Block size: 52428800, Block count: 2048
Disk usage: 107374182400
-------------------------------------------------------------------------------
138/2048 blocks | Processed 6%

The log file is still empty:
[root@localhost:/vmfs/volumes/58468b1e-752c135f-2ab0-1866dae9637a/xsi-dir] ls -l
a var/logs/
total 16
drwxr-xr-x 1 root root 420 Dec 15 14:38 .
drwxr-xr-x 1 root root 420 Dec 15 14:38 ..
-rwxrwxrwx 1 root root 0 Dec 15 14:38 xsibackup.log

New backup data directory showed up:
[root@localhost:/vmfs/volumes/58468b1e-752c135f-2ab0-1866dae9637a/xsi-dir] ls /v
mfs/volumes/Synology-SOS/backup/
20181216081843 20181217093148 data

Last edited by karpiq (2018-12-17 09:36:55)

admin · 2018-12-17 10:34:22

Well, you have a working cron and a working job script, you just need to put the ball through the round hole.
Did you assign proper execution permisssions on the job and write on the xsibackup.log?, they should be assigned automatically, but you never know.
Program your job to some point close in time and debug, we can't do that for you.

karpiq · 2018-12-17 10:55:02

Everyone can write to the log file and that's strange for me.

Job has the 700 permissions is it enough?

Thanks for your help

karpiq · 2018-12-18 12:41:04

So I've found the problem:
some "\" were missing in job file.

Now I have one more question:

I've set --backup-vms="CPLSV006169" parameter in job but xsi seems to ignore it, any idea why?

2018-12-18T12:36:01| VMs to backup:
---------------------------------------------------------------------------------------------------------------------------------
2018-12-18T12:36:01| 11 CPLSV006169 [localRaid5] CPLSV006169/CPLSV006169.vmx windows7Server64Guest vmx-11
2018-12-18T12:36:09| 13 bareos [localRaid5] bareos/bareos.vmx other26xLinux64Guest vmx-10 BACULA BACKUP
2018-12-18T12:36:12| 2 CPLSVSOS-DHPSFS [localRaid5] CPLSVSOS-DHPSFS/CPLSVSOS-DHPSFS.vmx windows8Server64Guest vmx-10 FS, DHCP, PS
2018-12-18T12:36:15| 6 Zentyal5.0 [localRaid5] Zentyal5.0/Zentyal5.0.vmx centos64Guest vmx-10 DC wenetrzny - Ubuntu
2018-12-18T12:36:19| 8 CPLSVSOS-iNODE [localRaid5] CPLSVSOS-iNODE/CPLSVSOS-iNODE.vmx ubuntu64Guest vmx-10

admin · 2018-12-18 16:04:02

Did you set [b]--backup-how=custom[/b]?

karpiq · 2018-12-22 20:33:57

This solved the problem.

The job runs fine now, but there is something wrong. This is how the log looks like for one of the vms and below you can see what is the result of the backup

2018-12-22T20:15:46| --backup-point found at /vmfs/volumes/Synology-SOS/backup (filesystem: NFS)
-------------------------------------------------------------------------------- -------------------------------------------------
2018-12-22T20:15:46| The backup room has been limited to 1500 gb.
-------------------------------------------------------------------------------- -------------------------------------------------
2018-12-22T20:15:46| Getting list of all VMs...
-------------------------------------------------------------------------------- -------------------------------------------------
2018-12-22T20:15:46| 1 CPLSVSOS-OPC [LocalDatastore_Raid5] CP LSVSOS-OPC/CPLSVSOS-OPC.vmx windows8Server64Guest vmx- 10
2018-12-22T20:15:47| 10 DCtest [LocalDatastore_Raid5] DC test/DCtest.vmx windows9_64Guest vmx- 13
2018-12-22T20:15:48| 12 CPLSV005998 [LocalDatastore_Raid5] CP LSV005998/CPLSV005998.vmx windows9Server64Guest vmx- 13
2018-12-22T20:15:48| 13 CPLSV006168 [LocalDatastore_Raid5] CP LSV006168_/CPLSV006168_.vmx windows7Server64Guest vmx- 13
2018-12-22T20:15:49| 9 Tesseract_DataCollector [LocalDatastore_Raid5] Te sseract_DataCollector/Tesseract_DataCollector.vmx centos7_64Guest vmx- 13 Tesseract CentOS DataCollector from Quality Machines
-------------------------------------------------------------------------------- -------------------------------------------------
2018-12-22T20:15:49| VMs to backup:
-------------------------------------------------------------------------------- -------------------------------------------------
2018-12-22T20:15:49| 1 CPLSVSOS-OPC [LocalDatastore_Raid5] CP LSVSOS-OPC/CPLSVSOS-OPC.vmx windows8Server64Guest vmx- 10
2018-12-22T20:15:50| 12 CPLSV005998 [LocalDatastore_Raid5] CP LSV005998/CPLSV005998.vmx windows9Server64Guest vmx- 13
2018-12-22T20:15:51| 13 CPLSV006168 [LocalDatastore_Raid5] CP LSV006168_/CPLSV006168_.vmx windows7Server64Guest vmx- 13
2018-12-22T20:15:57| 9 Tesseract_DataCollector [LocalDatastore_Raid5] Te sseract_DataCollector/Tesseract_DataCollector.vmx centos7_64Guest vmx- 13 Tesseract CentOS DataCollector from Quality Machines
-------------------------------------------------------------------------------- -------------------------------------------------
2018-12-22T20:15:59| Needed room: 641 Gb.
2018-12-22T20:15:59| Sparse size: 734 Gb.
2018-12-22T20:15:59| Available room: 1499 Gb.
-------------------------------------------------------------------------------- -------------------------------------------------
2018-12-22T20:16:00| [CPLSVSOS-OPC] Starting backup (size is 51200M on 51200M f ile)
-------------------------------------------------------------------------------- -------------------------------------------------
2018-12-22T20:16:00| XSIBackup will backup your VMs while they are running and will quiesce guest services too, so that users
2018-12-22T20:16:00| can continue to use the VM while the backup is taking plac e. You can also run cold and warm --backup-how
-------------------------------------------------------------------------------- -------------------------------------------------
2018-12-22T20:16:00| Hot backup selected for VM: [CPLSVSOS-OPC], will not be sw itched off
-------------------------------------------------------------------------------- -------------------------------------------------
2018-12-22T20:16:01| [CPLSVSOS-OPC] info: boot partition is MBR
-------------------------------------------------------------------------------- -------------------------------------------------
2018-12-22T20:16:01| [CPLSVSOS-OPC] info: Win64 OS (windows8Server64) detected on MBR, applying Windows algorithm
-------------------------------------------------------------------------------- -------------------------------------------------
2018-12-22T20:16:01| Removing snapshots, please wait...
-------------------------------------------------------------------------------- -------------------------------------------------
2018-12-22T20:16:02| Syncronizing config files
-------------------------------------------------------------------------------- -------------------------------------------------
-------------------------------------------------------------------------------- ------------
| Windows quiescing is not available in XSIBACKUP-FREE |
| Get XSIBACKUP-PRO at [url]https://33hops.com[/url] |
-------------------------------------------------------------------------------- ------------

2018-12-22T20:16:06| Backing up virtual disks...
-------------------------------------------------------------------------------- -------------------------------------------------
2018-12-22T20:16:06| DISK=/vmfs/volumes/LocalDatastore_Raid5/CPLSVSOS-OPC/CPLSV SOS-OPC-000001-delta.vmdk
2018-12-22T20:16:06| DISK=/vmfs/volumes/LocalDatastore_Raid5/CPLSVSOS-OPC/CPLSV SOS-OPC-000001.vmdk
2018-12-22T20:16:06| DISK=/vmfs/volumes/LocalDatastore_Raid5/CPLSVSOS-OPC/CPLSV SOS-OPC-Snapshot2.vmsn
2018-12-22T20:16:06| DISK=/vmfs/volumes/LocalDatastore_Raid5/CPLSVSOS-OPC/CPLSV SOS-OPC.vmdk
-------------------------------------------------------------------------------- -------------------------------------------------
(c) XSIDiff 1.1.1.4 licensed:
A full file copy will be performed, no meta-data available
Reading from file /vmfs/volumes/LocalDatastore_Raid5/CPLSVSOS-OPC/CPLSVSOS-OPC-0 00001.vmdk
Writing to file /vmfs/volumes/Synology-SOS/backup/20181222201543/CPLSVSOS-OPC/CP LSVSOS-OPC-000001.vmdk
Set input file offset to 0 bytes
100.00% done
Time taken: 1 seconds
Speed 1.00 mb/s
Overall speed 0.00 mb/s
-------------------------------------------------------------------------------- -------------------------------------------------
(c) XSIDiff 1.1.1.4 licensed:
A full file copy will be performed, no meta-data available
Reading from file /vmfs/volumes/LocalDatastore_Raid5/CPLSVSOS-OPC/CPLSVSOS-OPC-S napshot2.vmsn
Writing to file /vmfs/volumes/Synology-SOS/backup/20181222201543/CPLSVSOS-OPC/CP LSVSOS-OPC-Snapshot2.vmsn
Set input file offset to 0 bytes
100.00% done
Time taken: 1 seconds
Speed 1.00 mb/s
Overall speed 0.03 mb/s
-------------------------------------------------------------------------------- -------------------------------------------------
(c) XSIDiff 1.1.1.4 licensed:
A full file copy will be performed, no meta-data available
Reading from file /vmfs/volumes/LocalDatastore_Raid5/CPLSVSOS-OPC/CPLSVSOS-OPC.v mdk
Writing to file /vmfs/volumes/Synology-SOS/backup/20181222201543/CPLSVSOS-OPC/CP LSVSOS-OPC.vmdk
Set input file offset to 0 bytes
100.00% done
Time taken: 1 seconds
Speed 1.00 mb/s
Overall speed 0.00 mb/s
-------------------------------------------------------------------------------- -------------------------------------------------
2018-12-22T20:16:06| Blocksize is 52428800 bytes
-------------------------------------------------------------------------------- -------------------------------------------------
2018-12-22T20:16:06| Compression has been set
2018-12-22T20:16:06| Backing up via XSITools
-------------------------------------------------------------------------------- -------------------------------------------------
2018-12-22T20:16:06| File name: CPLSVSOS-OPC-flat.vmdk, File size: 53687091200
2018-12-22T20:16:06| Block size: 52428800, Block count: 1024
2018-12-22T20:16:06| Disk usage: 53687091200
-------------------------------------------------------------------------------- -------------------------------------------------
1024/1024 blocks | Processed 100%
Previous block count: 22066
Current block count: 22159
-------------------------------------------------------------------------------- -------------------------------------------------
Time taken: 219 seconds
Avg speed: 233 mb/s

These are the original files:
[root@ESXi02-SOS:~] ls -la /vmfs/volumes/LocalDatastore_Raid5/CPLSVSOS-OPC/
total 56857632
drwxr-xr-x 1 root root 2940 Dec 22 20:19 .
drwxr-xr-t 1 root root 2240 Dec 22 19:19 ..
-rw-r--r-- 1 root root 51 Oct 5 06:40 CPLSVSOS-OPC-ff89972c.hlog
-rw------- 1 root root 4294967296 Dec 8 13:41 CPLSVSOS-OPC-ff89972c.vswp
-rw------- 1 root root 53687091200 Dec 22 20:27 CPLSVSOS-OPC-flat.vmdk
-rw------- 1 root root 8684 Dec 22 20:20 CPLSVSOS-OPC.nvram
-rw------- 1 root root 529 Dec 22 20:19 CPLSVSOS-OPC.vmdk
-rw-r--r-- 1 root root 43 Dec 22 20:19 CPLSVSOS-OPC.vmsd
-rwxr-xr-x 1 root root 3263 Dec 22 20:19 CPLSVSOS-OPC.vmx
-rw------- 1 root root 0 Dec 8 13:41 CPLSVSOS-OPC.vmx.lck
-rw------- 1 root root 3192 Jan 15 2018 CPLSVSOS-OPC.vmxf
-rwxr-xr-x 1 root root 3270 Dec 22 20:19 CPLSVSOS-OPC.vmx~
-rw-r--r-- 1 root root 267087 Oct 20 13:06 vmware-19.log
-rw-r--r-- 1 root root 306113 Oct 24 06:54 vmware-20.log
-rw-r--r-- 1 root root 271993 Nov 3 03:11 vmware-21.log
-rw-r--r-- 1 root root 311290 Nov 17 01:31 vmware-22.log
-rw-r--r-- 1 root root 430364 Dec 8 08:52 vmware-23.log
-rw-r--r-- 1 root root 299210 Dec 8 12:39 vmware-24.log
-rw-r--r-- 1 root root 314173 Dec 22 20:20 vmware.log
-rw------- 1 root root 115343360 Dec 8 13:41 vmx-CPLSVSOS-OPC-4287207212-1.vswp
-rw------- 1 root root 115343360 Jun 28 11:40 vmx-CPLSVSOS-OPC-4287207212-2.vswp

And these is what I'm getting from backup:
[root@ESXi02-SOS:~] ls -la /vmfs/volumes/Synology-SOS/backup/20181222201543/CPLSVSOS-OPC/
total 112
drwxrwxrwx 1 1024 users 370 Dec 22 20:26 .
drwxrwxrwx 1 1024 users 68 Dec 22 20:35 ..
-rwxrwxrwx 1 1024 users 328 Dec 22 20:26 CPLSVSOS-OPC-000001.vmdk
-rwxrwxrwx 1 1024 users 31714 Dec 22 20:26 CPLSVSOS-OPC-Snapshot2.vmsn
-rwxrwxrwx 1 1024 users 41984 Dec 22 20:29 CPLSVSOS-OPC-flat.vmdk
-rwxrwxrwx 1 1024 users 63 Dec 22 20:26 CPLSVSOS-OPC-flat.vmdk.info
-rwxrwxrwx 1 1024 users 8684 Dec 22 20:26 CPLSVSOS-OPC.nvram
-rwxrwxrwx 1 1024 users 529 Dec 22 20:26 CPLSVSOS-OPC.vmdk
-rwxrwxrwx 1 1024 users 43 Dec 22 20:26 CPLSVSOS-OPC.vmsd
-rwxrwxrwx 1 1024 users 3114 Dec 22 20:26 CPLSVSOS-OPC.vmx
-rwxrwxrwx 1 1024 users 3192 Dec 22 20:26 CPLSVSOS-OPC.vmxf

admin · 2018-12-23 17:35:47

XSIBackup does not copy all files in your VM, just the files needed to have a working backup.

karpiq · 2018-12-24 07:18:58

Ok, but it copied 147KB from over 50GB of data. I don't think it's enough, i have no disk file copied properly in backup

admin · 2018-12-24 12:34:07

You are using [b][https://33hops.com/xsitools-vmfs-deduplication.html](c)XSITools[/url][/b] whcih is a deduplication engine that stores data in a deduplicated repository.

[url]https://33hops.com/xsitools-vmfs-deduplication.html[/url]

If you don't know what deduplication is and you don't want to learn what it is, we suggest that you use a regular copy method like: [b]--backup-prog=Vmkfstools[/b]

Forum ©XSIBackup: ©VMWare ©ESXi Backup Software

#1 2018-12-16 09:48:43

Empty logs and jobs not working with cron

#2 2018-12-16 15:20:13

Re: Empty logs and jobs not working with cron

#3 2018-12-17 09:35:10

Re: Empty logs and jobs not working with cron

#4 2018-12-17 10:34:22

Re: Empty logs and jobs not working with cron

#5 2018-12-17 10:55:02

Re: Empty logs and jobs not working with cron

#6 2018-12-18 12:41:04

Re: Empty logs and jobs not working with cron

#7 2018-12-18 16:04:02

Re: Empty logs and jobs not working with cron

#8 2018-12-22 20:33:57

Re: Empty logs and jobs not working with cron

#9 2018-12-23 17:35:47

Re: Empty logs and jobs not working with cron

#10 2018-12-24 07:18:58

Re: Empty logs and jobs not working with cron

#11 2018-12-24 12:34:07

Re: Empty logs and jobs not working with cron

Board footer