Code: Select all
[10.05.2019 14:52:15] <139767663291392> cli | Initializing new log filter.
[10.05.2019 14:52:15] <139767663291392> | ====================================================================================
[10.05.2019 14:52:15] <139767663291392> lpb | {
[10.05.2019 14:52:15] <139767663291392> lpb | Veeam Agent for Linux: veeamjobman.
[10.05.2019 14:52:15] <139767663291392> lpb | Version: 3.0.1.1046
[10.05.2019 14:52:15] <139767663291392> lpb | PID: 4738
[10.05.2019 14:52:15] <139767663291392> vmb | hostname: basis_demo
[10.05.2019 14:52:15] <139767663291392> vmb | uname
[10.05.2019 14:52:15] <139767663291392> vmb | sysname : Linux
[10.05.2019 14:52:15] <139767663291392> vmb | release : 4.15.0-48-generic
[10.05.2019 14:52:15] <139767663291392> vmb | version : #51-Ubuntu SMP Wed Apr 3 08:28:49 UTC 2019
[10.05.2019 14:52:15] <139767663291392> vmb | machine : x86_64
[10.05.2019 14:52:15] <139767663291392> lpb | }
[10.05.2019 14:52:15] <139767663291392> lpbcore| Connecting to veeamservice...
[10.05.2019 14:52:15] <139767663291392> | Configuration load.
[10.05.2019 14:52:15] <139767663291392> | Configuration load. ok.
[10.05.2019 14:52:15] <139767663291392> lpbcore| Connecting to veeamservice... ok.
[10.05.2019 14:52:15] <139767663291392> lpbman | Main thread has started.
[10.05.2019 14:52:15] <139767663291392> lpbcore| License information:
[10.05.2019 14:52:15] <139767663291392> lpbcore| License source: Veeam Backup & Replication
[10.05.2019 14:52:15] <139767663291392> lpbcore| Mode: Server
[10.05.2019 14:52:15] <139767663291392> lpbcore| LpbManSession: Processing commands.
[10.05.2019 14:52:15] <139767663291392> lpbcore| Sending PID: [4738].
[10.05.2019 14:52:15] <139767663291392> lpbcore| Sending Session UUID: [{55632720-987c-42f6-90d5-8bdde849de11}].
[10.05.2019 14:52:15] <139767663291392> lpbcore| Waiting for a command.
[10.05.2019 14:52:15] <139767663291392> lpbcore| LpbManSession: Starting managed backup job.
[10.05.2019 14:52:15] <139767663291392> lpbcore| Job UUID: [{181749a4-129e-4291-8584-ed6dd768719e}] (normal priority).
[10.05.2019 14:52:15] <139767663291392> lpbcore| System information:
[10.05.2019 14:52:15] <139767663291392> lpbcore| Running [lsb_release -a].
[10.05.2019 14:52:15] <139767663291392> lpbcore| Distributor ID: Ubuntu
[10.05.2019 14:52:15] <139767663291392> lpbcore| Description: Ubuntu 18.04.2 LTS
[10.05.2019 14:52:15] <139767663291392> lpbcore| Release: 18.04
[10.05.2019 14:52:15] <139767663291392> lpbcore| Codename: bionic
[10.05.2019 14:52:15] <139767663291392> lpbcore| Running [cat /etc/*release].
[10.05.2019 14:52:15] <139767663291392> lpbcore| DISTRIB_ID=Ubuntu
[10.05.2019 14:52:15] <139767663291392> lpbcore| DISTRIB_RELEASE=18.04
[10.05.2019 14:52:15] <139767663291392> lpbcore| DISTRIB_CODENAME=bionic
[10.05.2019 14:52:15] <139767663291392> lpbcore| DISTRIB_DESCRIPTION="Ubuntu 18.04.2 LTS"
[10.05.2019 14:52:15] <139767663291392> lpbcore| NAME="Ubuntu"
[10.05.2019 14:52:15] <139767663291392> lpbcore| VERSION="18.04.2 LTS (Bionic Beaver)"
[10.05.2019 14:52:15] <139767663291392> lpbcore| ID=ubuntu
[10.05.2019 14:52:15] <139767663291392> lpbcore| ID_LIKE=debian
[10.05.2019 14:52:15] <139767663291392> lpbcore| PRETTY_NAME="Ubuntu 18.04.2 LTS"
[10.05.2019 14:52:15] <139767663291392> lpbcore| VERSION_ID="18.04"
[10.05.2019 14:52:15] <139767663291392> lpbcore| HOME_URL="https://www.ubuntu.com/"
[10.05.2019 14:52:15] <139767663291392> lpbcore| SUPPORT_URL="https://help.ubuntu.com/"
[10.05.2019 14:52:15] <139767663291392> lpbcore| BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
[10.05.2019 14:52:15] <139767663291392> lpbcore| PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
[10.05.2019 14:52:15] <139767663291392> lpbcore| VERSION_CODENAME=bionic
[10.05.2019 14:52:15] <139767663291392> lpbcore| UBUNTU_CODENAME=bionic
[10.05.2019 14:52:15] <139767663291392> lpbcore| Running [lsblk].
[10.05.2019 14:52:15] <139767663291392> lpbcore| NAME MAJ:MIN RM SIZE RO TYPE MOUNTPOINT
[10.05.2019 14:52:15] <139767663291392> lpbcore| loop0 7:0 0 91.1M 1 loop /snap/core/6531
[10.05.2019 14:52:15] <139767663291392> lpbcore| loop1 7:1 0 89.4M 1 loop /snap/core/6818
[10.05.2019 14:52:15] <139767663291392> lpbcore| loop2 7:2 0 89.3M 1 loop /snap/core/6673
[10.05.2019 14:52:15] <139767663291392> lpbcore| sda 8:0 0 200G 0 disk
[10.05.2019 14:52:15] <139767663291392> lpbcore| ā”ā”€sda1 8:1 0 1M 0 part
[10.05.2019 14:52:15] <139767663291392> lpbcore| ā””ā”€sda2 8:2 0 200G 0 part /
[10.05.2019 14:52:15] <139767663291392> vmb | Sync repositories for backup server gbcloud.
[10.05.2019 14:52:15] <139767663291392> vmb | Available VBR repositories:
[10.05.2019 14:52:15] <139767663291392> vmb | id: [{88788f9e-d8f5-4eb4-bc4f-9b3f5403bcec}]; name: [Default Backup Repository].
[10.05.2019 14:52:15] <139767663291392> vmb | Updating repository [[gbcloud] Default Backup Repository] with UUID {88788f9e-d8f5-4eb4-bc4f-9b3f5403bcec}.
[10.05.2019 14:52:15] <139767663291392> vmb | Sync repositories for backup server gbcloud. ok.
[10.05.2019 14:52:15] <139767663291392> lpbcore| Process applications for job [name - IP].
[10.05.2019 14:52:15] <139767663291392> lpbcore| Delete old application job filters
[10.05.2019 14:52:15] <139767663291392> lpbcore| No applications set
[10.05.2019 14:52:15] <139767663291392> lpbcore| Job information:
[10.05.2019 14:52:15] <139767663291392> lpbcore| Job name: [name - IP]. ID: [{181749a4-129e-4291-8584-ed6dd768719e}].
[10.05.2019 14:52:15] <139767663291392> lpbcore| Job source:
[10.05.2019 14:52:15] <139767663291392> lpbcore| Included [All System] .
[10.05.2019 14:52:15] <139767663291392> lpbcore| Job destination:
[10.05.2019 14:52:15] <139767663291392> lpbcore| Target repository [[gbcloud] Default Backup Repository] ID [{88788f9e-d8f5-4eb4-bc4f-9b3f5403bcec}].
[10.05.2019 14:52:15] <139767663291392> lpbcore| VBR server [gbcloud] ID [{939c9962-641c-4d45-932d-e1fad7b07c84}]. FQDN: [gbcloud].
[10.05.2019 14:52:15] <139767663291392> lpbcore| Connection endpoints: [gbcloud:10006; IP:10006].
[10.05.2019 14:52:15] <139767663291392> lpbcore| Job options:
[10.05.2019 14:52:15] <139767663291392> lpbcore| Compression: [Lz4]
[10.05.2019 14:52:15] <139767663291392> lpbcore| Block size: [KbBlockSize1024]
[10.05.2019 14:52:15] <139767663291392> lpbcore| Retention max points: [7].
[10.05.2019 14:52:15] <139767663291392> lpbcore| Pre-freeze: []
[10.05.2019 14:52:15] <139767663291392> lpbcore| Post-thaw: []
[10.05.2019 14:52:15] <139767663291392> lpbcore| Pre-job: []
[10.05.2019 14:52:15] <139767663291392> lpbcore| Post-job: []
[10.05.2019 14:52:15] <139767663291392> lpbcore| IsSnapshotRequired: [true].
[10.05.2019 14:52:15] <139767663291392> lpbcore| Retry count: [3]
[10.05.2019 14:52:15] <139767663291392> lpbcore| Retry delay (ms): [600000]
[10.05.2019 14:52:15] <139767663291392> lpbcore| Indexing: File system indexing is disabled.
[10.05.2019 14:52:15] <139767663291392> lpbcore| Schedule: Disabled; Every day at 06:00.
[10.05.2019 14:52:15] <139767663291392> lpbcore| Active full schedule: Disabled; Every 1 day of every month.
[10.05.2019 14:52:15] <139767628924672> | Thread started. Thread id: 139767628924672, parent id: 139767663291392, role: Managed volume backup job execution
[10.05.2019 14:52:15] <139767628924672> lpbcore| ManagedBackupJobPerformer: Creating backup.
[10.05.2019 14:52:15] <139767663291392> lpbcore| LpbManSession: Starting managed backup job. ok.
[10.05.2019 14:52:15] <139767628924672> lpbcore| BObject ID: [{4cad50b6-fe37-4d43-a99a-b600990aebff}].
[10.05.2019 14:52:15] <139767620531968> | Thread started. Thread id: 139767620531968, parent id: 139767628924672, role: Session checker for Job: {181749a4-129e-4291-8584-ed6dd768719e}.
[10.05.2019 14:52:15] <139767612139264> | Thread started. Thread id: 139767612139264, parent id: 139767628924672, role: lease keeper
[10.05.2019 14:52:15] <139767628924672> vmb | [SessionLog][info] Preparing to backup.
[10.05.2019 14:52:15] <139767628924672> lpbcore| Enumerating backup objects.
[10.05.2019 14:52:15] <139767628924672> lpbcore| Creating job objects filter.
[10.05.2019 14:52:15] <139767628924672> lpbcore| Record type: [Include], object type: [AllSystem], value: []
[10.05.2019 14:52:15] <139767628924672> lpbcore| Creating job objects filter. ok.
[10.05.2019 14:52:15] <139767628924672> lpbcore| Enumerating all block devices...
[10.05.2019 14:52:15] <139767628924672> lpbcore| Ignored devices mask: [].
[10.05.2019 14:52:15] <139767628924672> lpbcore| Skip filtering: [false].
[10.05.2019 14:52:15] <139767628924672> lpbcore| Verbose logging: [false].
[10.05.2019 14:52:15] <139767628924672> lpbcore| WARN|Device [/dev/loop0] (7:0) with type [loop] is not supported for backup and WILL SKIPPED.
[10.05.2019 14:52:15] <139767628924672> lpbcore| WARN|Device [/dev/loop1] (7:1) with type [loop] is not supported for backup and WILL SKIPPED.
[10.05.2019 14:52:15] <139767628924672> lpbcore| WARN|Device [/dev/loop2] (7:2) with type [loop] is not supported for backup and WILL SKIPPED.
[10.05.2019 14:52:15] <139767628924672> lpbcore| WARN|Device [/dev/loop3] (7:3) with type [loop] is not supported for backup and WILL SKIPPED.
[10.05.2019 14:52:15] <139767628924672> lpbcore| WARN|Device [/dev/loop4] (7:4) with type [loop] is not supported for backup and WILL SKIPPED.
[10.05.2019 14:52:15] <139767628924672> lpbcore| WARN|Device [/dev/loop5] (7:5) with type [loop] is not supported for backup and WILL SKIPPED.
[10.05.2019 14:52:15] <139767628924672> lpbcore| WARN|Device [/dev/loop6] (7:6) with type [loop] is not supported for backup and WILL SKIPPED.
[10.05.2019 14:52:15] <139767628924672> lpbcore| WARN|Device [/dev/loop7] (7:7) with type [loop] is not supported for backup and WILL SKIPPED.
[10.05.2019 14:52:15] <139767628924672> lpbcore| Found device: [/dev/sda]. Device number: [8:0]; Type: [scsi].
[10.05.2019 14:52:15] <139767628924672> lpbcore| Link: [/dev/sda].
[10.05.2019 14:52:15] <139767628924672> lpbcore| Link: [/dev/block/8:0].
[10.05.2019 14:52:15] <139767628924672> lpbcore| Link: [/dev/disk/by-path/pci-0000:00:10.0-scsi-0:0:0:0].
[10.05.2019 14:52:15] <139767628924672> lpbcore| Partition table type: [gpt].
[10.05.2019 14:52:15] <139767628924672> lpbcore| Found device: [/dev/sda1]. Device number: [8:1]; Type: [scsi].
[10.05.2019 14:52:15] <139767628924672> lpbcore| Link: [/dev/sda1].
[10.05.2019 14:52:15] <139767628924672> lpbcore| Link: [/dev/block/8:1].
[10.05.2019 14:52:15] <139767628924672> lpbcore| Link: [/dev/disk/by-partuuid/261d8ecb-8842-4f3e-9c08-b312c88e6cea].
[10.05.2019 14:52:15] <139767628924672> lpbcore| Link: [/dev/disk/by-path/pci-0000:00:10.0-scsi-0:0:0:0-part1].
[10.05.2019 14:52:15] <139767628924672> lpbcore| Found device: [/dev/sda2]. Device number: [8:2]; Type: [scsi].
[10.05.2019 14:52:15] <139767628924672> lpbcore| Link: [/dev/sda2].
[10.05.2019 14:52:15] <139767628924672> lpbcore| Link: [/dev/block/8:2].
[10.05.2019 14:52:15] <139767628924672> lpbcore| Link: [/dev/disk/by-uuid/62510805-ee1e-4b15-8614-20b260647e9e].
[10.05.2019 14:52:15] <139767628924672> lpbcore| Link: [/dev/disk/by-partuuid/37a3650f-efae-4dbd-a046-38463016baac].
[10.05.2019 14:52:15] <139767628924672> lpbcore| Link: [/dev/disk/by-path/pci-0000:00:10.0-scsi-0:0:0:0-part2].
[10.05.2019 14:52:15] <139767628924672> lpbcore| Filesystem UUID: [62510805-ee1e-4b15-8614-20b260647e9e]; Type: [ext4]; Mount points: [/].
[10.05.2019 14:52:15] <139767628924672> lpbcore| [3] block devices were detected.
[10.05.2019 14:52:15] <139767628924672> lpbcore| Detecting whether we are running under recovery ISO.
[10.05.2019 14:52:15] <139767628924672> lpbcore| Recovery ISO: [0].
[10.05.2019 14:52:15] <139767628924672> lpbcore| Enumerating LVM devices...
[10.05.2019 14:52:15] <139767628924672> lpbcore| Should skip inactive LVs? [true].
[10.05.2019 14:52:15] <139767628924672> lpbcore| [0] LVM volume groups were detected.
[10.05.2019 14:52:15] <139767628924672> lpbcore| Enumerating BTRFS subvolumes...
[10.05.2019 14:52:15] <139767628924672> lpbcore| [0] BTRFS subvolumes were detected.
[10.05.2019 14:52:15] <139767628924672> lpbcore| Checking whether current system has stable btrfs driver version.
[10.05.2019 14:52:15] <139767628924672> lpbcore| Building backup objects.
[10.05.2019 14:52:15] <139767628924672> lpbcore| Find root enumerated objects for backup.
[10.05.2019 14:52:15] <139767628924672> lpbcore| Find REO for backup of object [sda] (DevNum_8:0-DevNode_/dev/sda-Size_214748364800-LogicalDisk).
[10.05.2019 14:52:15] <139767628924672> lpbcore| Found REO for backup: [sda] (DevNum_8:0-DevNode_/dev/sda-Size_214748364800-LogicalDisk).
[10.05.2019 14:52:15] <139767628924672> lpbcore| Find REO for backup of object [sda1] (DevNum_8:1-DevNode_/dev/sda1-Size_1048576).
[10.05.2019 14:52:15] <139767628924672> lpbcore| Found REO for backup: [sda] (DevNum_8:0-DevNode_/dev/sda-Size_214748364800-LogicalDisk).
[10.05.2019 14:52:15] <139767628924672> lpbcore| Find REO for backup of object [sda2] (DevNum_8:2-DevNode_/dev/sda2-Size_214745219072).
[10.05.2019 14:52:15] <139767628924672> lpbcore| Found REO for backup: [sda] (DevNum_8:0-DevNode_/dev/sda-Size_214748364800-LogicalDisk).
[10.05.2019 14:52:15] <139767628924672> lpbcore| Create disk backup object.
[10.05.2019 14:52:15] <139767628924672> lpbcore| Found filter for object [sda]({b40d14e8-c61d-41e3-a759-077fbcfe6fcd}). Record type: [Include], value: []
[10.05.2019 14:52:15] <139767628924672> lpbcore| No matching filters for object [{b40d14e8-c61d-41e3-a759-077fbcfe6fcd}]
[10.05.2019 14:52:15] <139767628924672> lpbcore| Found filter for object [sda1]({b40d14e8-c61d-41e3-a759-077fbcfe6fcd}/o1048576l1048576). Record type: [Include], value: []
[10.05.2019 14:52:15] <139767628924672> lpbcore| No matching filters for object [{b40d14e8-c61d-41e3-a759-077fbcfe6fcd}/o1048576l1048576]
[10.05.2019 14:52:15] <139767628924672> lpbcore| Partition [/dev/sda1] with index [1] should be backed up.
[10.05.2019 14:52:15] <139767628924672> lpbcore| Found filter for object [sda2]({b40d14e8-c61d-41e3-a759-077fbcfe6fcd}/o2097152l214745219072). Record type: [Include], value: []
[10.05.2019 14:52:15] <139767628924672> lpbcore| No matching filters for object [{b40d14e8-c61d-41e3-a759-077fbcfe6fcd}/o2097152l214745219072]
[10.05.2019 14:52:15] <139767628924672> lpbcore| No matching filters for object [\]
[10.05.2019 14:52:15] <139767628924672> lpbcore| Partition [/dev/sda2] with index [2] should be backed up.
[10.05.2019 14:52:15] <139767628924672> lpbcore| Detecting bootloader on device [/dev/sda].
[10.05.2019 14:52:15] <139767628924672> lpbcore| Detected GRUB 2 (v1.97-1.99).
[10.05.2019 14:52:15] <139767628924672> lpbcore| Device has GPT partition table.
[10.05.2019 14:52:15] <139767628924672> lpbcore| Found BIOS boot partition, partition number [1]. Partition size: [1048576].
[10.05.2019 14:52:15] <139767628924672> lpbcore| Detected bootloader type: [Grub2].
[10.05.2019 14:52:15] <139767628924672> lpbcore| BIOS bootloader on [/dev/sda] will be backed up.
[10.05.2019 14:52:15] <139767628924672> lpbcore| Disk [/dev/sda] will be backed up.
[10.05.2019 14:52:15] <139767628924672> lpbcore| Querying used space on sda.
[10.05.2019 14:52:15] <139767628924672> lpbcore| WARN|Failed to get used space on device [sda1].
[10.05.2019 14:52:15] <139767628924672> lpbcore| Partition sda1, size: 1048576, used: 0.
[10.05.2019 14:52:15] <139767628924672> lpbcore| Partition sda2, size: 214745219072, used: 26821304320.
[10.05.2019 14:52:15] <139767628924672> lpbcore| Used space: 26821304320.
[10.05.2019 14:52:15] <139767628924672> vmb | [JobSessionUpdater] Adding progress record size 214746267648, used size: 26821304320.
[10.05.2019 14:52:15] <139767628924672> lpbcore| Taking snapshot.
[10.05.2019 14:52:15] <139767628924672> lpbcore| Requesting snapshot for device sda1 [8:1].
[10.05.2019 14:52:15] <139767628924672> lpbcore| Requesting snapshot for device sda2 [8:2].
[10.05.2019 14:52:15] <139767628924672> vmb | [SessionLog][processing] Creating volume snapshot.
[10.05.2019 14:52:15] <139767628924672> lpbcore| WARN|Method invocation was not finalized. Method id [1]. Class: [lpbcorelib::interaction::ISnapshotOperation]
[10.05.2019 14:52:15] <139767628924672> lpbcore| ERR |Incompatible kernel module [dattobd] already loaded
[10.05.2019 14:52:15] <139767628924672> lpbcore| >> |--tr:Module compatibility check was failed
[10.05.2019 14:52:15] <139767628924672> lpbcore| >> |--tr:Failed to finish snapshot creation process.
[10.05.2019 14:52:15] <139767628924672> lpbcore| >> |--tr:Failed to execute method [1] for class [lpbcorelib::interaction::proxystub::CSnapshotOperationStub].
[10.05.2019 14:52:15] <139767628924672> lpbcore| >> |--tr:Failed to invoke method [1] in class [lpbcorelib::interaction::ISnapshotOperation].
[10.05.2019 14:52:15] <139767628924672> lpbcore| >> |An exception was thrown from thread [139767628924672].
[10.05.2019 14:52:15] <139767628924672> lpbcore| ERR |Failed to execute thaw script with status: fail.
[10.05.2019 14:52:15] <139767628924672> vmb | [SessionLog][error] Failed to create volume snapshot.
[10.05.2019 14:52:15] <139767628924672> lpbcore| Taking snapshot. Failed.
[10.05.2019 14:52:15] <139767620531968> | Thread finished. Role: 'Session checker for Job: {181749a4-129e-4291-8584-ed6dd768719e}.'.
[10.05.2019 14:52:15] <139767628924672> lpbcore| ManagedBackupJobPerformer: Creating backup. Failed.
[10.05.2019 14:52:15] <139767628924672> vmb | [SessionLog][error] Failed to perform managed backup.
[10.05.2019 14:52:15] <139767628924672> vmb | [SessionLog][error] Incompatible kernel module [dattobd] already loaded.
[10.05.2019 14:52:15] <139767628924672> lpbcore| ERR |Incompatible kernel module [dattobd] already loaded
[10.05.2019 14:52:15] <139767628924672> lpbcore| >> |--tr:Module compatibility check was failed
[10.05.2019 14:52:15] <139767628924672> lpbcore| >> |--tr:Failed to finish snapshot creation process.
[10.05.2019 14:52:15] <139767628924672> lpbcore| >> |--tr:Failed to execute method [1] for class [lpbcorelib::interaction::proxystub::CSnapshotOperationStub].
[10.05.2019 14:52:15] <139767628924672> lpbcore| >> |--tr:Failed to create volume snapshot.
[10.05.2019 14:52:15] <139767628924672> lpbcore| >> |Managed backup job has failed.
[10.05.2019 14:52:15] <139767628924672> lpbcore| >> |An exception was thrown from thread [139767628924672].
[10.05.2019 14:52:15] <139767663291392> | Closing socket device.
[10.05.2019 14:52:15] <139767663291392> lpbcore| LpbManSession: Processing commands. ok.
[10.05.2019 14:52:15] <139767663291392> | Closing socket device.
[10.05.2019 14:52:15] <139767612139264> | Thread finished. Role: 'lease keeper'.
[10.05.2019 14:52:15] <139767628924672> lpbcore| JOB STATUS: FAILED.
[10.05.2019 14:52:15] <139767628924672> | Thread finished. Role: 'Managed volume backup job execution'.
[10.05.2019 14:52:15] <139767663291392> | Closing socket device.
[10.05.2019 14:52:15] <139767663291392> | Closing socket device.
[10.05.2019 14:52:15] <139767663291392> lpbman | Application session has been finished.