Unsolved
This post is more than 5 years old
1 Message
0
2941
September 18th, 2018 02:00
Slice bounds out of range
Hello,
We are using Networker 9.2.1.3 with vproxy 2.1.1-41. Another backups on the same host work fine. They're on the same network, I've also checked through the firewall. They don't have access problems. Whatever I did, I wasn't successful on this machine. I changed the proxy, moved to another host. I'm constantly getting the following errors.
2018/09/18 02:13:21 NOTICE: [215] Logging to '/opt/emc/vproxy/runtime/logs/vbackupd/BackupVmSessions-237acfb5-b7fb-46cb-b1a5-b76cf63ae267.log' on host 'nwproxy03'.
2018/09/18 02:13:21 NOTICE: [215] Release: '2.1.1-62_1', Build number: '1', Build date: '2018-06-07T23:11:11Z'
2018/09/18 02:13:21 NOTICE: [215] Changing log level from INFO to TRACE.
2018/09/18 02:13:21 TRACE: [215] Using locale "en", 75 messages.
2018/09/18 02:13:21 TRACE: [215] Initialized disk status for 2000 - Hard disk 1 to Queued.
2018/09/18 02:13:21 TRACE: [215] Initialized disk status for 2001 - Hard disk 2 to Queued.
2018/09/18 02:13:21 TRACE: [215] Initialized disk status for 2002 - Hard disk 3 to Queued.
2018/09/18 02:13:21 NOTICE: [215] Starting backup of "TKSZERPQADEV" (vm-13019) logging at level "\x01" ...
2018/09/18 02:13:21 NOTICE: [215] BackupVmSessions supplied by client:
2018/09/18 02:13:21 NOTICE: [215] {
2018/09/18 02:13:21 NOTICE: [215] "Config": {
2018/09/18 02:13:21 NOTICE: [215] "SessionId": "237acfb5-b7fb-46cb-b1a5-b76cf63ae267",
2018/09/18 02:13:21 NOTICE: [215] "LogTag": "215",
2018/09/18 02:13:21 NOTICE: [215] "LogLevel": "TRACE",
2018/09/18 02:13:21 NOTICE: [215] "IdleTimeout": 300,
2018/09/18 02:13:21 NOTICE: [215] "AcceptedLanguage": "en",
2018/09/18 02:13:21 NOTICE: [215] "TransportModeRequested": "hotadd",
2018/09/18 02:13:21 NOTICE: [215] "Parallelism": 1,
2018/09/18 02:13:21 NOTICE: [215] "UseCbt": true,
2018/09/18 02:13:21 NOTICE: [215] "VimServerRef": {
2018/09/18 02:13:21 NOTICE: [215] "HostName": "vfvcanvc.portvmind.com.tr",
2018/09/18 02:13:21 NOTICE: [215] "TcpPort": 0,
2018/09/18 02:13:21 NOTICE: [215] "UserName": "administrator@vsphere.local",
2018/09/18 02:13:21 NOTICE: [215] "UserPassword": "********",
2018/09/18 02:13:21 NOTICE: [215] "ThumbPrint": "",
2018/09/18 02:13:21 NOTICE: [215] "HypervisorMode": "vSphere"
2018/09/18 02:13:21 NOTICE: [215] },
2018/09/18 02:13:21 NOTICE: [215] "VmSpec": {
2018/09/18 02:13:21 NOTICE: [215] "Name": "TKSZERPQADEV",
2018/09/18 02:13:21 NOTICE: [215] "VmMoref": "vm-13019",
2018/09/18 02:13:21 NOTICE: [215] "VirtualDisks": [
2018/09/18 02:13:21 NOTICE: [215] {
2018/09/18 02:13:21 NOTICE: [215] "Label": "Hard disk 1",
2018/09/18 02:13:21 NOTICE: [215] "Key": 2000
2018/09/18 02:13:21 NOTICE: [215] },
2018/09/18 02:13:21 NOTICE: [215] {
2018/09/18 02:13:21 NOTICE: [215] "Label": "Hard disk 2",
2018/09/18 02:13:21 NOTICE: [215] "Key": 2001
2018/09/18 02:13:21 NOTICE: [215] },
2018/09/18 02:13:21 NOTICE: [215] {
2018/09/18 02:13:21 NOTICE: [215] "Label": "Hard disk 3",
2018/09/18 02:13:21 NOTICE: [215] "Key": 2002
2018/09/18 02:13:21 NOTICE: [215] }
2018/09/18 02:13:21 NOTICE: [215] ],
2018/09/18 02:13:21 NOTICE: [215] "CustomFieldName": "Last EMC vProxy Backup",
2018/09/18 02:13:21 NOTICE: [215] "CustomFieldValue": "Backup Server=vfnetworker, Policy=TOKSOZ, Workflow=GUNLUKBACKUP, Action=backup, JobId=671009"
2018/09/18 02:13:21 NOTICE: [215] },
2018/09/18 02:13:21 NOTICE: [215] "SnapshotSpec": {
2018/09/18 02:13:21 NOTICE: [215] "Name": "NetWorker Backup Snapshot",
2018/09/18 02:13:21 NOTICE: [215] "Description": "Snapshot is created as part of protecting this VM by EMC NetWorker VProxy.",
2018/09/18 02:13:21 NOTICE: [215] "Quiesce": false,
2018/09/18 02:13:21 NOTICE: [215] "QuiesceTimeout": 30,
2018/09/18 02:13:21 NOTICE: [215] "QuiesceType": "COPY",
2018/09/18 02:13:21 NOTICE: [215] "DumpMemory": false,
2018/09/18 02:13:21 NOTICE: [215] "RemoveAll": false,
2018/09/18 02:13:21 NOTICE: [215] "Consolidate": false
2018/09/18 02:13:21 NOTICE: [215] },
2018/09/18 02:13:21 NOTICE: [215] "TargetSpec": {
2018/09/18 02:13:21 NOTICE: [215] "DeviceType": "DataDomain",
2018/09/18 02:13:21 NOTICE: [215] "HostName": "vfdd6300node01.portvmind.com.tr",
2018/09/18 02:13:21 NOTICE: [215] "UserName": "networker",
2018/09/18 02:13:21 NOTICE: [215] "UserPassword": "********",
2018/09/18 02:13:21 NOTICE: [215] "BackupMode": "VSS",
2018/09/18 02:13:21 NOTICE: [215] "BackupPath": "vfnetworker/DD6300POOL//vfnetworker/DD6300POOL/39/67/d0db6fab-00000006-3ea0c0dd-5ba0c0dd-06c45000-42689756",
2018/09/18 02:13:21 NOTICE: [215] "PreviousBackupPath": "",
2018/09/18 02:13:21 NOTICE: [215] "CurrentBackupPath": "/vfnetworker/DD6300POOL/active/d0db6fab-00000006-3ea0c0dd-5ba0c0dd-06c45000-42689756",
2018/09/18 02:13:21 NOTICE: [215] "VBABackup": {
2018/09/18 02:13:21 NOTICE: [215] "VBABackupPath": "",
2018/09/18 02:13:21 NOTICE: [215] "VBATempPath": ""
2018/09/18 02:13:21 NOTICE: [215] }
2018/09/18 02:13:21 NOTICE: [215] },
2018/09/18 02:13:21 NOTICE: [215] "GuestSpec": {
2018/09/18 02:13:21 NOTICE: [215] "VmGuestInfo": {
2018/09/18 02:13:21 NOTICE: [215] "VmName": "",
2018/09/18 02:13:21 NOTICE: [215] "MorefId": "",
2018/09/18 02:13:21 NOTICE: [215] "UserName": "",
2018/09/18 02:13:21 NOTICE: [215] "UserPassword": "",
2018/09/18 02:13:21 NOTICE: [215] "InstallationAuthorized": false,
2018/09/18 02:13:21 NOTICE: [215] "RemoveInstallation": false,
2018/09/18 02:13:21 NOTICE: [215] "AdminUser": "",
2018/09/18 02:13:21 NOTICE: [215] "AdminPassword": ""
2018/09/18 02:13:21 NOTICE: [215] },
2018/09/18 02:13:21 NOTICE: [215] "AppName": "",
2018/09/18 02:13:21 NOTICE: [215] "BackupType": "FULL",
2018/09/18 02:13:21 NOTICE: [215] "ApplicationData": {
2018/09/18 02:13:21 NOTICE: [215] "BackupTime": "Type=string",
2018/09/18 02:13:21 NOTICE: [215] "Mode": "Type=string"
2018/09/18 02:13:21 NOTICE: [215] }
2018/09/18 02:13:21 NOTICE: [215] },
2018/09/18 02:13:21 NOTICE: [215] "ZeroFillUnusedSectors": false,
2018/09/18 02:13:21 NOTICE: [215] "AutoEnableCbt": true,
2018/09/18 02:13:21 NOTICE: [215] "AutoRepairCbt": true,
2018/09/18 02:13:21 NOTICE: [215] "FallbackCbtThreshold": 0,
2018/09/18 02:13:21 NOTICE: [215] "FallbackTransportMode": "",
2018/09/18 02:13:21 NOTICE: [215] "DeprecatedREST": false,
2018/09/18 02:13:21 NOTICE: [215] "ReadBufferMB": 0,
2018/09/18 02:13:21 NOTICE: [215] "WriteBufferKB": 0,
2018/09/18 02:13:21 NOTICE: [215] "BufferCount": 0
2018/09/18 02:13:21 NOTICE: [215] },
2018/09/18 02:13:21 NOTICE: [215] "Actions": {
2018/09/18 02:13:21 NOTICE: [215] "ChangeSession": "",
2018/09/18 02:13:21 NOTICE: [215] "DeleteSession": "/api/v1/BackupVmSessions/237acfb5-b7fb-46cb-b1a5-b76cf63ae267",
2018/09/18 02:13:21 NOTICE: [215] "CancelActivity": "/api/v1/BackupVmSessions/237acfb5-b7fb-46cb-b1a5-b76cf63ae267/activity",
2018/09/18 02:13:21 NOTICE: [215] "GetSession": "/api/v1/BackupVmSessions/237acfb5-b7fb-46cb-b1a5-b76cf63ae267",
2018/09/18 02:13:21 NOTICE: [215] "GetSessionLog": "/api/v1/BackupVmSessions/237acfb5-b7fb-46cb-b1a5-b76cf63ae267/log",
2018/09/18 02:13:21 NOTICE: [215] "GetAllSessions": "/api/v1/BackupVmSessions"
2018/09/18 02:13:21 NOTICE: [215] },
2018/09/18 02:13:21 NOTICE: [215] "Status": {
2018/09/18 02:13:21 NOTICE: [215] "State": "Queued",
2018/09/18 02:13:21 NOTICE: [215] "Description": "",
2018/09/18 02:13:21 NOTICE: [215] "Progress": 0,
2018/09/18 02:13:21 NOTICE: [215] "Error": {
2018/09/18 02:13:21 NOTICE: [215] "Text": "",
2018/09/18 02:13:21 NOTICE: [215] "Code": 0
2018/09/18 02:13:21 NOTICE: [215] },
2018/09/18 02:13:21 NOTICE: [215] "StartTime": "",
2018/09/18 02:13:21 NOTICE: [215] "EndTime": "",
2018/09/18 02:13:21 NOTICE: [215] "ApplicationData": "",
2018/09/18 02:13:21 NOTICE: [215] "ApplicationVersion": "",
2018/09/18 02:13:21 NOTICE: [215] "BytesToMove": 0,
2018/09/18 02:13:21 NOTICE: [215] "BytesMoved": 0,
2018/09/18 02:13:21 NOTICE: [215] "TransportModeUsed": "",
2018/09/18 02:13:21 NOTICE: [215] "BackupModeUsed": "",
2018/09/18 02:13:21 NOTICE: [215] "VirtualDiskStatus": null,
2018/09/18 02:13:21 NOTICE: [215] "AppStatus": {
2018/09/18 02:13:21 NOTICE: [215] "Progress": 0,
2018/09/18 02:13:21 NOTICE: [215] "TotalBytesToProcess": 0,
2018/09/18 02:13:21 NOTICE: [215] "TotalBytesProcessed": 0,
2018/09/18 02:13:21 NOTICE: [215] "TotalObjectsToProcess": 0,
2018/09/18 02:13:21 NOTICE: [215] "TotalObjectsProcessed": 0,
2018/09/18 02:13:21 NOTICE: [215] "ObjectType": "",
2018/09/18 02:13:21 NOTICE: [215] "Custom": null
2018/09/18 02:13:21 NOTICE: [215] }
2018/09/18 02:13:21 NOTICE: [215] }
2018/09/18 02:13:21 NOTICE: [215] }
2018/09/18 02:13:21 TRACE: [215] Set state to running.
2018/09/18 02:13:21 TRACE: [215] Sent initial status to vProxy Engine.
2018/09/18 02:13:21 TRACE: [215] Opening session to target device "vfdd6300node01.portvmind.com.tr" ...
2018/09/18 02:13:21 NOTICE: [215] DD Model = "DD6300", DDOS Version = "Data Domain OS 6.0.2.0-575017", DD Boost Version = "3.4.0.4-569771".
2018/09/18 02:13:21 TRACE: [215] Opened session to target device "vfdd6300node01.portvmind.com.tr".
2018/09/18 02:13:21 INFO: [215] DDOS version 6.0.2.0-575017 compatible.
2018/09/18 02:13:21 TRACE: [215] Verifying that target directory "/vfnetworker/DD6300POOL/active/d0db6fab-00000006-3ea0c0dd-5ba0c0dd-06c45000-42689756" on "vfdd6300node01.portvmind.com.tr" is empty.
2018/09/18 02:13:21 TRACE: [215] Opening target directory "/vfnetworker/DD6300POOL/active/d0db6fab-00000006-3ea0c0dd-5ba0c0dd-06c45000-42689756" on DD "vfdd6300node01.portvmind.com.tr".
2018/09/18 02:13:21 INFO: [215] Opened target directory "/vfnetworker/DD6300POOL/active/d0db6fab-00000006-3ea0c0dd-5ba0c0dd-06c45000-42689756" on DD "vfdd6300node01.portvmind.com.tr".
2018/09/18 02:13:21 TRACE: [215] Closing target directory "/vfnetworker/DD6300POOL/active/d0db6fab-00000006-3ea0c0dd-5ba0c0dd-06c45000-42689756" on DD "vfdd6300node01.portvmind.com.tr".
2018/09/18 02:13:21 INFO: [215] Closed target directory "/vfnetworker/DD6300POOL/active/d0db6fab-00000006-3ea0c0dd-5ba0c0dd-06c45000-42689756" on DD "vfdd6300node01.portvmind.com.tr".
2018/09/18 02:13:21 TRACE: [215] Starting go routine to periodically send status updates...
2018/09/18 02:13:21 TRACE: [215] Starting go routine to listen for cancel from vProxy engine.
2018/09/18 02:13:21 INFO: [215] Connected to session on vCenter 'vfvcanvc.portvmind.com.tr' Version '6.0.0 build-7462485, API:6.0', Uuid:9559208E-8DD5-400B-B4B6-D6C030C797C3.
2018/09/18 02:13:21 TRACE: [215] Locating virtual machine associated with IP address 172.30.100.137 ...
2018/09/18 02:13:21 INFO: [215] The vProxy's virtual machine has MORef ID = "vm-14297".
2018/09/18 02:13:21 TRACE: [215] Searching for virtual machine with MORef "vm-13019" ...
2018/09/18 02:13:21 TRACE: [215] Querying vCenter for definition of virtual machine with MORef of "vm-13019" ...
2018/09/18 02:13:22 INFO: [215] Found virtual machine "TKSZERPQADEV" with MORef "vm-13019".
2018/09/18 02:13:22 TRACE: [215] Checking for excessive disk chain length ...
2018/09/18 02:13:22 TRACE: [215] Virtual disk key 2000 has 1 child disks.
2018/09/18 02:13:22 TRACE: [215] Virtual disk key 2001 has 1 child disks.
2018/09/18 02:13:22 TRACE: [215] Virtual disk key 2002 has 1 child disks.
2018/09/18 02:13:22 TRACE: [215] Check host'172.30.16.17' connectionState:'connected',inMaintenanceMode:'false', powerState:poweredOn
2018/09/18 02:13:22 INFO: [215] Host '172.30.16.17' is running VMware ESXi 6.0.0 build-5050593.
2018/09/18 02:13:22 INFO: [215] Locking VM.
2018/09/18 02:13:22 TRACE: [215] Setting custom attribute 'EMC vProxy Session' value for object vm-13019 to 'Operation=Backup, StartTime=2018-09-18T02:13:21Z, vProxy=nwproxy03, SessionId=237acfb5-b7fb-46cb-b1a5-b76cf63ae267' ...
2018/09/18 02:13:22 INFO: [215] Set custom attribute 'EMC vProxy Session' value for object vm-13019 to 'Operation=Backup, StartTime=2018-09-18T02:13:21Z, vProxy=nwproxy03, SessionId=237acfb5-b7fb-46cb-b1a5-b76cf63ae267'.
2018/09/18 02:13:23 TRACE: [215] Custom attribute 'EMC vProxy FLR Session' not found.
2018/09/18 02:13:23 INFO: [215] VM '[DS49] TKSZERPQADEV/TKSZERPQADEV.vmx' not hosted on VSAN.
2018/09/18 02:13:23 TRACE: [215] Checking for old snapshots to cleanup ...
2018/09/18 02:13:23 TRACE: [215] No pre-existing snapshots found.
2018/09/18 02:13:23 INFO: [215] Disabling storage migration of virtual machine ...
2018/09/18 02:13:23 TRACE: [215] Attempting to disable storage migration of virtual machine "vm-13019" ...
2018/09/18 02:13:23 INFO: [215] There are 2 certificates available at vfvcanvc.portvmind.com.tr. First one will be used.
2018/09/18 02:13:23 NOTICE: [215] Storage migration successfully disabled: "vm-13019" @ "vfvcanvc.portvmind.com.tr"
2018/09/18 02:13:23 INFO: [215] Creating snapshot of virtual machine ...
2018/09/18 02:13:23 TRACE: [215] Sending create snapshot request to Snapshot Manager ...
2018/09/18 02:13:27 INFO: [215] Create snapshot request succeeded.
2018/09/18 02:13:27 INFO: [215] Found snapshot "snapshot-14299".
2018/09/18 02:13:27 TRACE: [215] Checking CBT for "Hard disk 1" (disk key = 2000).
2018/09/18 02:13:27 TRACE: [215] Examining datastore Datastore:datastore-6502, type 'VMFS'.
2018/09/18 02:13:27 TRACE: [215] Checking CBT for "Hard disk 2" (disk key = 2001).
2018/09/18 02:13:27 TRACE: [215] Examining datastore Datastore:datastore-6502, type 'VMFS'.
2018/09/18 02:13:27 TRACE: [215] Checking CBT for "Hard disk 3" (disk key = 2002).
2018/09/18 02:13:27 TRACE: [215] Examining datastore Datastore:datastore-6502, type 'VMFS'.
2018/09/18 02:13:28 NOTICE: [215] VM passed configuration checks.
2018/09/18 02:13:28 TRACE: [215] Checking for leftover VDDK tmp directory "/tmp/vmware-root/42282ec9-1e9b-5fad-7aae-1dfd193cd8b1-vm-13019" ...
2018/09/18 02:13:28 TRACE: [215] VDDK tmp directory "/tmp/vmware-root/42282ec9-1e9b-5fad-7aae-1dfd193cd8b1-vm-13019" doesn't exist.
2018/09/18 02:13:28 TRACE: [215] Opening VDDK connection to "vm-13019" @ "vfvcanvc.portvmind.com.tr" using "hotadd" ...
2018/09/18 02:13:28 INFO: [215] Opened VDDK connection to "vm-13019"@"vfvcanvc.portvmind.com.tr".
2018/09/18 02:13:28 INFO: [215] Opened VDDK connection to "vm-13019@vfvcanvc.portvmind.com.tr".
2018/09/18 02:13:28 TRACE: [215] Getting Virtual Machine Config ...
2018/09/18 02:13:28 TRACE: [215] Getting 3 Virtual Machine Config File Descriptor ...
2018/09/18 02:13:28 TRACE: [215] Downloading "[DS49] TKSZERPQADEV/TKSZERPQADEV.vmx" and saving to "vm-13019-config-file-0.cfg" ...
2018/09/18 02:13:28 INFO: [215] Created VM configuration file "/vfnetworker/DD6300POOL/active/d0db6fab-00000006-3ea0c0dd-5ba0c0dd-06c45000-42689756/vm-13019-config-file-0.cfg".
2018/09/18 02:13:28 TRACE: [215] Finding folder with MORef "group-v22" ...
2018/09/18 02:13:28 INFO: [215] Found folder "vm" with MORef "group-v22".
2018/09/18 02:13:28 TRACE: [215] Finding datacenter with MORef "datacenter-21" ...
2018/09/18 02:13:28 INFO: [215] Found datacenter "VFESENYURT" having MORef "datacenter-21".
2018/09/18 02:13:28 TRACE: [215] vc version 6.0.0:false
2018/09/18 02:13:28 TRACE: [215] Downloading contents of config file from URL "https://vfvcanvc.portvmind.com.tr/folder/TKSZERPQADEV/TKSZERPQADEV.vmx?dcPath=VFESENYURT&dsName=DS49"
2018/09/18 02:13:28 TRACE: [215] Creating HTTP Get request to download contents of config file "[DS49] TKSZERPQADEV/TKSZERPQADEV.vmx".
2018/09/18 02:13:28 TRACE: [215] Starting download contents of config file "[DS49] TKSZERPQADEV/TKSZERPQADEV.vmx".
2018/09/18 02:13:29 INFO: [215] Downloaded contents of config file "[DS49] TKSZERPQADEV/TKSZERPQADEV.vmx".
2018/09/18 02:13:29 INFO: [215] downloaded VM configuration file "/vfnetworker/DD6300POOL/active/d0db6fab-00000006-3ea0c0dd-5ba0c0dd-06c45000-42689756/vm-13019-config-file-0.cfg", size 8571
2018/09/18 02:13:29 TRACE: [215] Closing VM configuration file "/vfnetworker/DD6300POOL/active/d0db6fab-00000006-3ea0c0dd-5ba0c0dd-06c45000-42689756/vm-13019-config-file-0.cfg" ...
2018/09/18 02:13:29 INFO: [215] Closed VM configuration file "/vfnetworker/DD6300POOL/active/d0db6fab-00000006-3ea0c0dd-5ba0c0dd-06c45000-42689756/vm-13019-config-file-0.cfg" ...
2018/09/18 02:13:29 TRACE: [215] Downloading "[DS49] TKSZERPQADEV" and saving to "vm-13019-config-file-1.cfg" ...
2018/09/18 02:13:29 INFO: [215] Created VM configuration file "/vfnetworker/DD6300POOL/active/d0db6fab-00000006-3ea0c0dd-5ba0c0dd-06c45000-42689756/vm-13019-config-file-1.cfg".
2018/09/18 02:13:29 TRACE: [215] Closing VM configuration file "/vfnetworker/DD6300POOL/active/d0db6fab-00000006-3ea0c0dd-5ba0c0dd-06c45000-42689756/vm-13019-config-file-1.cfg" ...
2018/09/18 02:13:29 INFO: [215] Closed VM configuration file "/vfnetworker/DD6300POOL/active/d0db6fab-00000006-3ea0c0dd-5ba0c0dd-06c45000-42689756/vm-13019-config-file-1.cfg" ...
2018/09/18 02:13:29 INFO: [215] Disconnecting VDDK from "vm-13019" @ "vfvcanvc.portvmind.com.tr"...
2018/09/18 02:13:29 INFO: [215] Closed VDDK connection to "vm-13019"@"vfvcanvc.portvmind.com.tr".
2018/09/18 02:13:29 INFO: [215] Closed VDDK connection to "vm-13019"@"vfvcanvc.portvmind.com.tr".
2018/09/18 02:13:29 INFO: [215] No disks of target virtual machine were attached to vProxy's virtual machine.
2018/09/18 02:13:29 TRACE: [215] Checking for leftover VDDK tmp directory "/tmp/vmware-root/42282ec9-1e9b-5fad-7aae-1dfd193cd8b1-vm-13019" ...
2018/09/18 02:13:29 TRACE: [215] VDDK tmp directory "/tmp/vmware-root/42282ec9-1e9b-5fad-7aae-1dfd193cd8b1-vm-13019" doesn't exist.
2018/09/18 02:13:29 TRACE: [215] Sending remove snapshot request to Snapshot Manager ...
2018/09/18 02:13:29 INFO: [215] Remove snapshot request accepted by Snapshot Manager.
2018/09/18 02:13:29 TRACE: [215] Setting custom attribute 'Last EMC vProxy Backup' value for object vm-13019 to 'Backup Server=vfnetworker, Policy=TOKSOZ, Workflow=GUNLUKBACKUP, Action=backup, JobId=671009, StartTime=2018-09-18T02:13:21Z, EndTime=2018-09-18T02:13:29Z' ...
2018/09/18 02:13:29 INFO: [215] Set custom attribute 'Last EMC vProxy Backup' value for object vm-13019 to 'Backup Server=vfnetworker, Policy=TOKSOZ, Workflow=GUNLUKBACKUP, Action=backup, JobId=671009, StartTime=2018-09-18T02:13:21Z, EndTime=2018-09-18T02:13:29Z'.
2018/09/18 02:13:29 INFO: [215] Enabling storage migration of virtual machine ...
2018/09/18 02:13:29 TRACE: [215] Attempting to enable storage migration for "vm-13019" ...
2018/09/18 02:13:29 INFO: [215] Storage migration successfully enabled: "vm-13019" @ "vfvcanvc.portvmind.com.tr"
2018/09/18 02:13:29 INFO: [215] Storage migration enabled.
2018/09/18 02:13:29 TRACE: [215] Unlocking VM ...
2018/09/18 02:13:29 TRACE: [215] Attempt #1 to clear virtual machine's custom field lock "EMC vProxy Session" ...
2018/09/18 02:13:29 TRACE: [215] Setting custom attribute 'EMC vProxy Session' value for object vm-13019 to '' ...
2018/09/18 02:13:29 INFO: [215] Set custom attribute 'EMC vProxy Session' value for object vm-13019 to ''.
2018/09/18 02:13:29 INFO: [215] Unlocked virtual machine.
2018/09/18 02:13:29 INFO: [215] Disconnected from session on vCenter 'vfvcanvc.portvmind.com.tr'.
2018/09/18 02:13:29 TRACE: [215] Closing session with target device "vfdd6300node01.portvmind.com.tr" ...
2018/09/18 02:13:29 INFO: [215] Closed session with target device "vfdd6300node01.portvmind.com.tr".
2018/09/18 02:13:29 PANIC: [215] Internal error occurred, see log file: runtime error: slice bounds out of range.
2018/09/18 02:13:29 PANIC: [215] goroutine 52 [running]:
2018/09/18 02:13:29 PANIC: [215] common/dontpanic.AssessPanic(0x7f257ee791c0, 0x7f257f260450, 0x7f257f260450, 0x1, 0x7f257e21b28c, 0x595402)
2018/09/18 02:13:29 PANIC: [215] /space/jenkins/dpadswci/workspace/vproxy/vproxy-2.1.1/vproxy/vproxy-core/vproxy-packages/vproxy/rpmbuild-106948/SOURCES/golang/src/common/dontpanic/dontpanic.go:78 +0x121
2018/09/18 02:13:29 PANIC: [215] sessions/backup/backup_vm.(*VMBackupSession).DontPanic(0xc42021c000, 0xc420b49700, 0xed3325641, 0x23f4fa26)
2018/09/18 02:13:29 PANIC: [215] /space/jenkins/dpadswci/workspace/vproxy/vproxy-2.1.1/vproxy/vproxy-core/vproxy-packages/vproxy/rpmbuild-106948/SOURCES/golang/src/sessions/backup/backup_vm/backup_vm.go:153 +0x8e
2018/09/18 02:13:29 PANIC: [215] panic(0x7f257ee791c0, 0x7f257f260450)
2018/09/18 02:13:29 PANIC: [215] /space/jenkins/dpadswci/workspace/vproxy/vproxy-2.1.1/vproxy/vproxy-core/proxy/.external-resources/go/src/runtime/panic.go:489 +0x2e7
2018/09/18 02:13:29 PANIC: [215] sessions/backup/backup_vm.(*VMBackupSession).downloadVmFile(0xc42021c000, 0xc420452000, 0xc420492280, 0x13, 0xc4201e3d00, 0x1a, 0x0, 0x0)
2018/09/18 02:13:29 PANIC: [215] /space/jenkins/dpadswci/workspace/vproxy/vproxy-2.1.1/vproxy/vproxy-core/vproxy-packages/vproxy/rpmbuild-106948/SOURCES/golang/src/sessions/backup/backup_vm/backup_vm.go:2166 +0x109f
2018/09/18 02:13:29 PANIC: [215] sessions/backup/backup_vm.(*VMBackupSession).downloadVmConfigFile(0xc42021c000, 0xc420452000, 0xc420b548a0, 0x1, 0x2)
2018/09/18 02:13:29 PANIC: [215] /space/jenkins/dpadswci/workspace/vproxy/vproxy-2.1.1/vproxy/vproxy-core/vproxy-packages/vproxy/rpmbuild-106948/SOURCES/golang/src/sessions/backup/backup_vm/backup_vm.go:1934 +0x64
2018/09/18 02:13:29 PANIC: [215] sessions/backup/backup_vm.(*VMBackupSession).initBackupDescriptor(0xc42021c000, 0xc420452000, 0xc420026680, 0xc4205c8340, 0xc420a34480, 0xc420a2e630, 0xc420a2e600, 0x0)
2018/09/18 02:13:29 PANIC: [215] /space/jenkins/dpadswci/workspace/vproxy/vproxy-2.1.1/vproxy/vproxy-core/vproxy-packages/vproxy/rpmbuild-106948/SOURCES/golang/src/sessions/backup/backup_vm/backup_vm.go:1745 +0x8fe
2018/09/18 02:13:29 PANIC: [215] sessions/backup/backup_vm.(*VMBackupSession).Run(0xc42021c000)
2018/09/18 02:13:29 PANIC: [215] /space/jenkins/dpadswci/workspace/vproxy/vproxy-2.1.1/vproxy/vproxy-core/vproxy-packages/vproxy/rpmbuild-106948/SOURCES/golang/src/sessions/backup/backup_vm/backup_vm.go:1064 +0x2742
2018/09/18 02:13:29 PANIC: [215] created by sessions/backup/sessions.(*BackupVm).Run
2018/09/18 02:13:29 PANIC: [215] /space/jenkins/dpadswci/workspace/vproxy/vproxy-2.1.1/vproxy/vproxy-core/vproxy-packages/vproxy/rpmbuild-106948/SOURCES/golang/src/sessions/backup/sessions/sessions.go:186 +0x50e
2018/09/18 02:13:29 TRACE: [215] Checking final status...
2018/09/18 02:13:29 TRACE: [215] Set state to failed.
2018/09/18 02:13:29 ERROR: [215] Backup has FAILED.: Internal error occurred, see log file: runtime error: slice bounds out of range.
2018/09/18 02:13:29 TRACE: [215] Sending final status to vProxy Engine ...
2018/09/18 02:13:29 INFO: [215] Sent final status to vProxy Engine.
2018/09/18 02:13:29 INFO: [215] Go routine sending status updates has completed.
2018/09/18 02:13:29 INFO: [215] Go routine listening for cancel messages from vProxy engine has completed.
2018/09/18 02:13:29 NOTICE: [215] Backup session is exiting
TonyK63
5 Posts
0
February 5th, 2019 00:00
Probably the original writer already solved this also, but in case somebody else stumbles on this...
We had the same problem, tried everything. As a last resort we removed the guest from the vSphere inventory and added it back again.
And this finally helped!
SistemasAlter
7 Posts
0
November 19th, 2019 12:00
Hello,
I'm coming across the same issue, and would like to know if there might be another solution without having to remove the vm from vsphere inventory...hopefully a solution which prevents me from having to turn off the vm
Thanks.
crazyrov
4 Operator
•
1.3K Posts
0
November 21st, 2019 00:00
@SistemasAlter,
Can you please provide more details? Have you checked the backup logs on the vProxy hosts to see if you get a more accurate reason for the backup failure ?
SistemasAlter
7 Posts
0
November 21st, 2019 02:00
Hello @crazyrov
I get the next logs in the vproxy server:
2019/11/21 10:25:20 INFO: Saved snapshot map to "/opt/emc/vproxy/runtime/state/vbackupd/SnapshotMaps.gob".
2019/11/21 10:25:20 INFO: Remove Snapshot Stats: Success: 6464; Failures: 0; Retries: 0; Avg Time: 4.007778823s; Worst Time: 17m45.217433312s
So it seam like its creating the snap correctly, but still I get the slice bounds out of range in the NW Console and backup failed
2019/11/21 10:28:10 NOTICE: [41] "Actions": {
2019/11/21 10:28:10 NOTICE: [41] "ChangeSession": "",
2019/11/21 10:28:10 NOTICE: [41] "DeleteSession": "/api/v1/BackupVmSessions/26ddc03f-138c-4d70-8ffa-f755b226e425",
2019/11/21 10:28:10 NOTICE: [41] "CancelActivity": "/api/v1/BackupVmSessions/26ddc03f-138c-4d70-8ffa-f755b226e425/activity",
2019/11/21 10:28:10 NOTICE: [41] "GetSession": "/api/v1/BackupVmSessions/26ddc03f-138c-4d70-8ffa-f755b226e425",
2019/11/21 10:28:10 NOTICE: [41] "GetSessionLog": "/api/v1/BackupVmSessions/26ddc03f-138c-4d70-8ffa-f755b226e425/log",
2019/11/21 10:28:10 NOTICE: [41] "GetAllSessions": "/api/v1/BackupVmSessions"
2019/11/21 10:28:10 NOTICE: [41] },
2019/11/21 10:28:10 NOTICE: [41] "Status": {
2019/11/21 10:28:10 NOTICE: [41] "State": "Failure",
2019/11/21 10:28:10 NOTICE: [41] "Description": "Internal error occurred, see log file: runtime error: slice bounds out of range.",
2019/11/21 10:28:10 NOTICE: [41] "Progress": 0,
2019/11/21 10:28:10 NOTICE: [41] "Error": {
2019/11/21 10:28:10 NOTICE: [41] "Text": "Backup has FAILED.: Internal error occurred, see log file: runtime error: slice bounds out of range.",
2019/11/21 10:28:10 NOTICE: [41] "Code": 1007
2019/11/21 10:28:10 NOTICE: [41] },
Let me know if this is healpfull or you need any other log, the main log, from the backup session looks exacly the same as the one in the main post.
Regards,
SistemasAlter
7 Posts
0
November 21st, 2019 07:00
Hi @crazyrov
I get the same exact log file as the one in the original post.
Any idea why?
Thanks
crazyrov
4 Operator
•
1.3K Posts
0
November 22nd, 2019 03:00
@SistemasAlter
Have you tried creating a snapshot on VCenter once? It looks more like an application exception and I think its being caused by VCenter and not NetWorker. Please checks the logs on VCenter for this backups and also You might want to reach out to support for this
SistemasAlter
7 Posts
0
November 25th, 2019 02:00
Hi @crazyrov,
I have tried creating a snapshot via vsphere and it works properly, in fact, in vsphere logs, I only get Networker task events as failed, stating Backup failed. Only this VM fails from all the VMs configured in the workflow.
Do you need some other log which can help determine the problem?
Thanks in advance for your help.
Regards.
crazyrov
4 Operator
•
1.3K Posts
0
November 25th, 2019 20:00
@SistemasAlter, one last step i could suggest is to remove the VM from all the protection groups that it has been assigned to. Then add it back again and test a backups. However at this point I would suggest you reach out to support for assistance.
SistemasAlter
7 Posts
0
December 17th, 2019 00:00
Hello,
Just to inform in case someone comes across the same problem, after discussing the issue with Dell Emc Support we've been able to solvent the problem performing a storage vMotion.
https://support.emc.com/kb/533774
Thanks for your help.
Regards,
Alejandro