GRT disabled backup hung at

ronnieshih · ‎07-08-2013

Backup Exec 2010 R3 with VMWare infrastructure backup option installed. I'm geting this error on only 1 VM:

0xe0009579 - Unable to copy the virtual machine disk using the VMware VixDiskLib

Error writing file data

I have the Advanced open file option checked to use Microsoft Volume Shadow Copy service with the "System" snapshot provider, after reading another post about this issue. The server is purely a file server.

When I run the vssadmin list writers command on the guest VM, everything is stable with no errors. I have already uninstalled then reinstalled the agent. VMWare tools is installed and I have not uninstalled that yet.

thanks!

ronnieshih · ‎07-08-2013

I should add that GRT is enabled. I'm trying an non-GRT backup to see what happens.

SuperBrain · ‎07-08-2013

Do you have Backup Exec 2010 R3 Service Pack 1 installed? If not, please see the following article :

http://www.symantec.com/docs/TECH168488

There is also a link provided at the bottom (Related Documents section) for BE 2010 R3 SP1 download.

ronnieshih · ‎07-08-2013

Yes I do. I have SP2 installed plus I have hotfix 195395 installed

http://www.symantec.com/business/support/index?page=content&id=TECH195395

lmosla · ‎07-08-2013

What version of VMware are you using? You have already reinstalled the agent but check to see if the VMware Tools VSS Provider is still installed. See here: To confirm the VMware Snapshot provider is correctly uninstalled, confirm the following

ronnieshih · ‎07-08-2013

VMWare 5.0 . Every other VM backs up just fine, even Exchange 2010 sp3 with GRT enabled.

I have verified that the VMWare Snapshot Provider isn't in Services, the VSS folder doesn't exist under c:\program files\vmware tools directory.

The backup with GRT disabled is in progress and I will update shortly. As described before, I have the option of "System" under Microsoft volume shadow copy selected, perhaps I should try backup exec provider next.... given that the disabled GRT backup still fails.

ronnieshih · ‎07-08-2013

GRT disabled backup hung at the end the job and never completed. I had to reboot the backup server in order to terminate it.

Now back to square one with GRT enabled and the snapshot provider option not selected. Results pending

ronnieshih · ‎07-08-2013

GRT disabled, received the exact same error message.

pkh · ‎07-08-2013

Push out the remote agent to the VM again and then reboot the VM.

ronnieshih · ‎07-09-2013

Yep, uninstalled the agent, re-pushed the agent, rebooted the server.

Both GRT and non-GRT backup ends up with the VixDiskLib error. I'm out of ideas, any diag logs I can look at?

Gurvinder · ‎07-09-2013

Please enable following registry on media server and run just the file server VM Job :

Go to HKEY_LOCAL_MACHINE\SOFTWARE\Symantec\Backup Exec for Windows\Backup Exec\Engine\VMware Agent.

VMware Agent debug log level to 1

Go to HKEY_LOCAL_MACHINE\SOFTWARE\Symantec\Backup Exec for Windows\Backup Exec\Engine\Logging

Set the value for CreateDebugLog to 1

The log will be created at BE Install Path\Logs. Look for errors towards the end of Beremote log (when the job fails) and post a part of it.

Thanks

ronnieshih · ‎07-10-2013

I just followed your step and I think this is the log file here. Backup ran against only that one VM machine.

<<<<<<<<<<<< LOGGING ON >>>>>>>>>>>>>>>>>>>

[1764] 07/10/13 09:10:07 [server] - JobEngine::LaunchJob

[1764] 07/10/13 09:10:07 [server] - RunJobWithGuidAndServer( {A12BDBE1-07B4-4168-AF5F-DFA524B631AE}, BK1 ) = 0

[6184] 07/10/13 09:10:07 [server] - Thread for job VM Backup Test-VM Backup Test-VM Backup Test ({A12BDBE1-07B4-4168-AF5F-DFA524B631AE}) starting

[6184] 07/10/13 09:10:07 [ndmp\ndmpclient] - viaNetwork enabled 0

[6184] 07/10/13 09:10:07 [ndmp\ndmpclient] - viaNetwork useAny 0

[6184] 07/10/13 09:10:07 [ndmp\ndmpclient] - viaNetwork protocol 0

[6184] 07/10/13 09:10:07 [ndmp\ndmpclient] - viaNetwork subnet ---><---

[6184] 07/10/13 09:10:07 [ndmp\ndmpclient] - viaNetwork MAC ---><---

[6184] 07/10/13 09:10:07 [ndmp\ndmpclient] - viaNetwork IPv4 Enabled 0

[6184] 07/10/13 09:10:07 [ndmp\ndmpclient] - viaNetwork IPv4 subnetAddress 0.0.0.0

[6184] 07/10/13 09:10:07 [ndmp\ndmpclient] - viaNetwork IPv4 subnetMask 0.0.0.0

[6184] 07/10/13 09:10:07 [ndmp\ndmpclient] - viaNetwork IPv4 autoObtain 0

[6184] 07/10/13 09:10:07 [ndmp\ndmpclient] - viaNetwork IPv4 physical

[6184] 07/10/13 09:10:07 [ndmp\ndmpclient] - viaNetwork selectedProtocol 0

[6184] 07/10/13 09:10:07 [ndmp\ndmpclient] - viaNetwork InterfaceIndexProtocol 0

[6184] 07/10/13 09:10:07 [ndmp\ndmpclient] - viaNetwork InterfaceIndex 0

[6184] 07/10/13 09:10:07 [ndmp\ndmpclient] - viaNetwork subnet <zero>

[6184] 07/10/13 09:10:07 [ndmp\ndmpclient] - viaNetwork PrefixLength 0

[6184] 07/10/13 09:10:07 [ndmp\ndmpclient] - viaNetwork ipAddr <zero>

[6184] 07/10/13 09:10:07 [ndmp\ndmpclient] - viaNetwork FallBackOptions 0xF Protocol Tunnel NIC Subnet

[6880] 07/10/13 09:10:07 [server] - Updating status for: 'VM Backup Test-VM Backup Test-VM Backup Test' (0x0 0x0)

[6880] 07/10/13 09:10:07 [server] - Status for: 'VM Backup Test-VM Backup Test-VM Backup Test' updated

[6184] 07/10/13 09:10:07 [server] - Checking for Evaluation expiration.

[6184] 07/10/13 09:10:07 [engapi] - ENGSCRPT: ConvertDeviceName osId = 0X4c

[6184] 07/10/13 09:10:07 [engapi] - ENGSCRPT: IN - oldDeviceName = VMVCB::\\10.200.1.40\VCGuestVm\(DC)ha-datacenter(DC)\vm\FS1

[6184] 07/10/13 09:10:07 [engapi] - ENGSCRPT: OUT - newName = VMVCB::\\10.200.1.40\VCGuestVm\(DC)ha-datacenter(DC)\vm\FS1

[6184] 07/10/13 09:10:07 [engapi] - SetupCryptInfoInBSD: Backup encryption options: bHWEncryption=0,bSWEncryption=0,bSWEncryptionIfNoHW=0

[6184] 07/10/13 09:10:07 [engapi] - ENGSCRPT: No script found

[6184] 07/10/13 09:10:07 [server] - Failed to Load AllowExcludes key, We will update DR file evenif there are userExcludes. Error: 5

[6184] 07/10/13 09:10:07 [server] - MountMultiple: Created MountThread thread 7940

[6276] 07/10/13 09:10:07 [server] - DeviceManager: incoming event fired

[6276] 07/10/13 09:10:07 [server] - DeviceManager: Executing RequestDeviceCall from thread 7940.

[6276] 07/10/13 09:10:07 [server] - DeviceManager: processing pending requests

[6276] 07/10/13 09:10:07 [server] - DeviceManager: Processing device request for thread 7940.

[6276] 07/10/13 09:10:07 [server] - DeviceManager: query cache miss

[6276] 07/10/13 09:10:07 [server] - Available and held drives from the pool

[6276] 07/10/13 09:10:07 [server] - Deduplication Storage Folder 0001:1 {9ff8b84c-83c3-4069-91c9-e4318c9df3fd}

[6276] 07/10/13 09:10:07 [server] - Deduplication Storage Folder 0001:2 {df7819a8-55c2-4ab8-9710-d951b2699fd6}

[6276] 07/10/13 09:10:07 [server] - Drives not in use by the Engine

[6276] 07/10/13 09:10:07 [server] - Deduplication Storage Folder 0001:1 {9ff8b84c-83c3-4069-91c9-e4318c9df3fd}

[6276] 07/10/13 09:10:07 [server] - Deduplication Storage Folder 0001:2 {df7819a8-55c2-4ab8-9710-d951b2699fd6}

[6276] 07/10/13 09:10:07 [server] - Drives available (not in use and not held)

[6276] 07/10/13 09:10:07 [server] - Deduplication Storage Folder 0001:1 {9ff8b84c-83c3-4069-91c9-e4318c9df3fd}

[6276] 07/10/13 09:10:07 [server] - Deduplication Storage Folder 0001:2 {df7819a8-55c2-4ab8-9710-d951b2699fd6}

[6276] 07/10/13 09:10:07 [server] - DeviceManager: Handing out session {1b073a8f-5d12-4842-9a08-e64cd2544aaf} based on available drive:

[6276] 07/10/13 09:10:07 [server] - Deduplication Storage Folder 0001:1 {9ff8b84c-83c3-4069-91c9-e4318c9df3fd}

[6276] 07/10/13 09:10:07 [server] - DeviceManager: returned result to caller 0x00000000

[6276] 07/10/13 09:10:07 [server] - DeviceManager: going to sleep for 900000 msecs

[7940] 07/10/13 09:10:07 [server] - BackupJob::MountThread : Clearing device host as IsDeviceOST is TRUE and RMAEnableDirectAccess is FALSE.

[7940] 07/10/13 09:10:07 [server] - BackupJob::MountThread : Device path hint : m_deviceHost.empty() is TRUE

[7940] 07/10/13 09:10:07 [server] - BackupJob: thread id 0x00001F04 acquired device Deduplication Storage Folder 0001:1.

[7940] 07/10/13 09:10:07 [server] - BackupJob: thread id 0x00001F04 trying to mount appending volume.

[7940] 07/10/13 09:10:07 [server] - BackupJob: thread id 0x00001F04 unable to mount appending volume, attempting scratch mount.

[6880] 07/10/13 09:10:12 [server] - Updating status for: 'VM Backup Test-VM Backup Test-VM Backup Test' (0x0 0x8)

[6880] 07/10/13 09:10:12 [server] - Status for: 'VM Backup Test-VM Backup Test-VM Backup Test' updated

[7940] 07/10/13 09:10:19 [server] - Updating session {1b073a8f-5d12-4842-9a08-e64cd2544aaf} with drive Deduplication Storage Folder 0001:2 {df7819a8-55c2-4ab8-9710-d951b2699fd6}

[7940] 07/10/13 09:10:19 [server] - BackupJob: thread id 0x00001F04 medium successfully mounted.

[6184] 07/10/13 09:10:19 [server] - Job::GetTargetNdmpServerName(): Execute(ADAMM_MOVER_EXECUTE_GET_SERVER_INFO) No server found.

[6184] 07/10/13 09:10:19 [server] - Media Label: OST00000027-4A66CCDDD64A3FF6

[6184] 07/10/13 09:10:19 [server] - Media Label: {8d7127bf-d420-490c-b4cf-6c1f1c8211bb}

[6184] 07/10/13 09:10:19 [server] - Overwrite Protected Until: 7/31/2013 9:10:18 AM

[6184] 07/10/13 09:10:19 [server] - Appendable Until: 7/16/2013 9:10:18 AM

[6184] 07/10/13 09:10:19 [tapealrt] - TAPEALERT: Get TapeAlert Flags Return Code = 0X0

[6184] 07/10/13 09:10:19 [tapealrt] - TAPEALERT: TapeAlert Device Flag = 0X0

[6184] 07/10/13 09:10:19 [tapealrt] - TAPEALERT: TapeAlert Changer Flag = 0X0

[6184] 07/10/13 09:10:19 [tapealrt] - TAPEALERT: Get TapeAlert Flags Return Code = 0X0

[6184] 07/10/13 09:10:19 [server] - Job Family ID: {4384FFAC-67AE-468B-8DE0-9983013AF781}

[6184] 07/10/13 09:10:19 [beutil] - VM-Metadata: GetRefCatMetadataFromDB: Entered.

[6184] 07/10/13 09:10:19 [beutil] - VM-Metadata: GetRefCatMetadataFromDB: Before main metadata loop.

[6184] 07/10/13 09:10:19 [beutil] - VM-Metadata: GetRefCatMetadataFromDB: PropertyID == REFERENCE_CATALOG_ID.

[6184] 07/10/13 09:10:19 [beutil] - VM-Metadata: GetRefCatMetadataFromDB: Release MAJOR == MALTA.

[6184] 07/10/13 09:10:19 [beutil] - ReadRefCatBlobMaltaVersion() VM-MetaData: Entered

[6184] 07/10/13 09:10:19 [beutil] - ReadRefCatBlobMaltaVersion() VM-MetaData: Entered exterior for loop

[6184] 07/10/13 09:10:19 [beutil] - ReadRefCatBlobMaltaVersion() VM-MetaData: Entered interior for loop

[6184] 07/10/13 09:10:19 [beutil] - ReadRefCatBlobMaltaVersion() VM-MetaData: SKIPPING... pBSD->dle_name = VMVCB::\\10.200.1.40\VCGuestVm\(DC)ha-datacenter(DC)\vm\FS1, pDeviceName = VMVCB::\\10.200.1.40\VCGuestVm\(DC)ha-datacenter(DC)\vm\kks4

[6184] 07/10/13 09:10:19 [server] - Deduplication Storage Folder 0001:2 Block size: 65536

[6184] 07/10/13 09:10:19 [server] - Deduplication Storage Folder 0001:2 Buffer size: 65536

[6184] 07/10/13 09:10:19 [server] - Deduplication Storage Folder 0001:2 Num buffers: 10

[6184] 07/10/13 09:10:19 [server] - Deduplication Storage Folder 0001:2 High water: 0

[6184] 07/10/13 09:10:19 [loops] - NDMPAgentConnector:SetupConnection(): Data Server = BK1

[6184] 07/10/13 09:10:19 [ndmp\ndmpcomm] - Could not resolve the "bews-ndmp" or the "ndmp" service, error code: 10109, using port 10000

[6184] 07/10/13 09:10:19 [ndmp\ndmpcomm] - ndmpConnectEx: 'BK1' resolves to the local machine itself. So, we will try and connect to a loopback address ...

[6184] 07/10/13 09:10:19 [ndmp\ndmpcomm] - ndmpConnectEx : Control Connection information: A connection was established between end-points [::1]:58506 and [::1]:10000.

[6184] 07/10/13 09:10:20 [ndmp\ndmpclient] - NDMP version 3 connection CONNECTED

[6184] 07/10/13 09:10:20 [loops] - NDMPAgentConnector::AuthenticateClient(): Using SSPI authentication with SLA/DLA as a fallback

[6184] 07/10/13 09:10:20 [loops] - NDMPAgentConnector::ConnectAuthUseSSPIasDefault(): Attempting SSPI authentication...

[6184] 07/10/13 09:10:20 [ndmp\ndmpclient] - connectClientAuth(): agent is on local loopback, skipping SSL connection...

[6184] 07/10/13 09:10:20 [ndmp\ndmpcomm] - NDMP_SSPI: InitializeSecurityContext status 0x00090312 in 0 out 49

[6184] 07/10/13 09:10:20 [ndmp\ndmpcomm] - NDMP_SSPI: InitializeSecurityContext status 0x00000000 in 202 out 88

[6184] 07/10/13 09:10:20 [ndmp\ndmpcomm] - NDMP_SSPI: client authenticated with server

[6184] 07/10/13 09:10:20 [loops] - NDMPAgentConnector::ConnectAuthUseSSPIasDefault(): SSPI authentication success.

[6184] 07/10/13 09:10:20 [loops] - Enabling Shared Buffers Connection type

[6184] 07/10/13 09:10:20 [loops] - NDMPAgentConnector::EndConnection(): Data Server = BK1

[6184] 07/10/13 09:10:20 [loops] - Enter CheckHostBSDsForSnaps

[6184] 07/10/13 09:10:20 [loops] - Exit CheckHostBSDsForSnaps: false

[6184] 07/10/13 09:10:20 [loops] - NDMPAgentConnector:SetupConnection(): Data Server = BK1

[6184] 07/10/13 09:10:20 [ndmp\ndmpcomm] - Could not resolve the "bews-ndmp" or the "ndmp" service, error code: 10109, using port 10000

[6184] 07/10/13 09:10:20 [ndmp\ndmpcomm] - ndmpConnectEx: 'BK1' resolves to the local machine itself. So, we will try and connect to a loopback address ...

[6184] 07/10/13 09:10:20 [ndmp\ndmpcomm] - ndmpConnectEx : Control Connection information: A connection was established between end-points [::1]:58508 and [::1]:10000.

[6184] 07/10/13 09:10:20 [ndmp\ndmpclient] - NDMP version 3 connection CONNECTED

[6184] 07/10/13 09:10:20 [ndmp\ndmpclient] - connectClientAuth(): agent is on local loopback, skipping SSL connection...

[6184] 07/10/13 09:10:21 [loops] - Enabling Shared Buffers Connection type

[6184] 07/10/13 09:10:21 [loops] - PDI - Querying application server(\\BK1) for PDI support.

[6184] 07/10/13 09:10:21 [loops] - Application server(\\BK1) supports PDI

[6184] 07/10/13 09:10:21 [loops] - Querying PDI data store server(BK1) for PDI support.

[6184] 07/10/13 09:10:21 [loops] - NDMPAgentConnector:SetupConnection(): Data Server = BK1

[6184] 07/10/13 09:10:21 [ndmp\ndmpcomm] - Could not resolve the "bews-ndmp" or the "ndmp" service, error code: 10109, using port 10000

[6184] 07/10/13 09:10:21 [ndmp\ndmpcomm] - ndmpConnectEx: 'BK1' resolves to the local machine itself. So, we will try and connect to a loopback address ...

[6184] 07/10/13 09:10:21 [ndmp\ndmpcomm] - ndmpConnectEx : Control Connection information: A connection was established between end-points [::1]:58512 and [::1]:10000.

[6184] 07/10/13 09:10:21 [ndmp\ndmpclient] - NDMP version 3 connection CONNECTED

[6184] 07/10/13 09:10:21 [loops] - NDMPAgentConnector::AuthenticateClient(): Using SSPI authentication with SLA/DLA as a fallback

[6184] 07/10/13 09:10:21 [loops] - NDMPAgentConnector::ConnectAuthUseSSPIasDefault(): Attempting SSPI authentication...

[6184] 07/10/13 09:10:21 [ndmp\ndmpclient] - connectClientAuth(): agent is on local loopback, skipping SSL connection...

[6184] 07/10/13 09:10:21 [ndmp\ndmpcomm] - NDMP_SSPI: InitializeSecurityContext status 0x00090312 in 0 out 49

[6184] 07/10/13 09:10:21 [ndmp\ndmpcomm] - NDMP_SSPI: InitializeSecurityContext status 0x00000000 in 202 out 88

[6184] 07/10/13 09:10:21 [ndmp\ndmpcomm] - NDMP_SSPI: client authenticated with server

[6184] 07/10/13 09:10:21 [loops] - NDMPAgentConnector::ConnectAuthUseSSPIasDefault(): SSPI authentication success.

[6184] 07/10/13 09:10:21 [loops] - Enabling Shared Buffers Connection type

[6184] 07/10/13 09:10:21 [loops] - PDI data store server(BK1) supports PDI

[6184] 07/10/13 09:10:21 [loops] - NDMPAgentConnector::EndConnection(): Data Server = BK1

[6184] 07/10/13 09:10:21 [loops] - PDI processor needed.

[6184] 07/10/13 09:10:21 [loops] - Failed to Load AllowExcludes key, We will update DR file evenif there are userExcludes. Error: 5

[6184] 07/10/13 09:10:21 [loops] - NDMPHostBackupEngine::CollectMetaDataForOneVirtualMachineBeforeBackup: entered

[6184] 07/10/13 09:10:21 [loops] - NDMPHostBackupEngine::GetGuestComputerName: entered

[6880] 07/10/13 09:10:22 [server] - Updating status for: 'VM Backup Test-VM Backup Test-VM Backup Test' (0x0 0xB)

[6880] 07/10/13 09:10:22 [server] - Status for: 'VM Backup Test-VM Backup Test-VM Backup Test' updated

[6184] 07/10/13 09:10:23 [loops] - NDMPHostBackupEngine::GetGuestComputerName: exiting void function

[6184] 07/10/13 09:10:23 [fsys\shared] - ClusterVirutalNameToNodeName failed

[6184] 07/10/13 09:10:23 [loops] - NDMPHostBackupEngine::ConnectToVirtualMachine: entered PDI Operation Type 1 PDIDataTransferPhase 1

[6184] 07/10/13 09:10:23 [loops] - NDMPHostBackupEngine::ConnectToVirtualMachine: VM friendly name '\(DC)ha-datacenter(DC)\vm\FS1' guest computer name 'FS1.kkworx.local'

[6184] 07/10/13 09:10:23 [loops] - NDMPAgentConnector:SetupConnection(): Data Server = FS1.kkworx.local

[6184] 07/10/13 09:10:23 [ndmp\ndmpcomm] - Could not resolve the "bews-ndmp" or the "ndmp" service, error code: 10109, using port 10000

[6184] 07/10/13 09:10:23 [ndmp\ndmpcomm] - ndmpConnectEx: Querying the neighbour advertisement cache to discover information on 'FS1.kkworx.local' ...

[6184] 07/10/13 09:10:23 [ndmp\ndmpcomm] - ndmpConnectEx : Control Connection information: A connection was established between end-points [FE80::484D:1A61:41C5:2848%11]:58545 and [FE80::9195:66FB:76CB:8A11%11]:10000.

[6184] 07/10/13 09:10:23 [ndmp\ndmpclient] - NDMP version 3 connection CONNECTED

[6184] 07/10/13 09:10:23 - SSL connection using version TLSv1

[6184] 07/10/13 09:10:23 - SSL connection using cipher AES256-SHA

[6184] 07/10/13 09:10:23 [ndmp\ndmpclient] - secureNDMPConnection: SECURITY ENABLED!!

[6184] 07/10/13 09:10:23 [loops] - IsLocalAgent:beclass::BEConvertServerNamePlus returned error: 87

[6184] 07/10/13 09:10:23 [loops] - NDMPHostBackupEngine::ConnectToVirtualMachine: returning 0x0

[6184] 07/10/13 09:10:23 [loops] - NDMPHostBackupEngine::RequestVirtualMachineMetaDataCollectionBeforeBackup: entered

[6184] 07/10/13 09:10:23 [loops] - NDMPHostBackupEngine::RequestVirtualMachineMetaDataCollectionBeforeBackup: status 0 0x0

[6184] 07/10/13 09:10:23 [loops] - NDMPHostBackupEngine::RequestVirtualMachineMetaDataCollectionBeforeBackup: reply result 0 0x0

[6184] 07/10/13 09:10:23 [loops] - NDMPHostBackupEngine::RequestVirtualMachineMetaDataCollectionBeforeBackup: returning 0x0

[6184] 07/10/13 09:10:23 [loops] - NDMPHostBackupEngine::DisconnectFromVirtualMachine: entered

[6184] 07/10/13 09:10:23 - SSL Shutdown clean

[6184] 07/10/13 09:10:23 [loops] - NDMPAgentConnector::EndConnection(): Data Server = FS1.kkworx.local

[6184] 07/10/13 09:10:23 [loops] - NDMPHostBackupEngine::DisconnectFromVirtualMachine: returning 0x0

[6184] 07/10/13 09:10:23 [loops] - NDMPHostBackupEngine::CollectMetaDataForOneVirtualMachineBeforeBackup: returning 0x0

[6184] 07/10/13 09:10:23 [tpfmt] - TF_OpenTape()

[6184] 07/10/13 09:10:23 [tpfmt] - TF_GetChannel( ) reusing channel 04A2C150

[6184] 07/10/13 09:10:23 [tpfmt] - TF_GetDriveContext ...

sessionGuid = {1b073a8f-5d12-4842-9a08-e64cd2544aaf}

initAsync = 1

[6184] 07/10/13 09:10:23 [tpfmt] - TF_MoverAsyncInit(): Started ProcessRequest thread 7120

[6184] 07/10/13 09:10:23 [tpfmt] - HARDWARE COMPRESSION ===> Compression is NOT configurable.

[6184] 07/10/13 09:10:23 [tpfmt] - HARDWARE ENCRYPTION ===> Encryption is NOT supported.

[6184] 07/10/13 09:10:23 [tpfmt] - GET_DRV_INF: bsize = 1024

[6184] 07/10/13 09:10:23 [tpfmt] - GET_DRV_INF: preferredBlockSize = 65536

[6184] 07/10/13 09:10:23 [tpfmt] - TF_GetDriveContext returning 0x00000000, context = 4D59D90

[6184] 07/10/13 09:10:23 [tpfmt] - Allocated 2 buffers, size 65536 bytes, total used: 131328

[6184] 07/10/13 09:10:23 [tpfmt] - HARDWARE COMPRESSION ===> Compression is NOT configurable.

[6184] 07/10/13 09:10:23 [tpfmt] - HARDWARE ENCRYPTION ===> Encryption is NOT supported.

[6184] 07/10/13 09:10:23 [tpfmt] - GET_DRV_INF: bsize = 1024

[6184] 07/10/13 09:10:23 [tpfmt] - GET_DRV_INF: preferredBlockSize = 65536

[6184] 07/10/13 09:10:23 [loops] - PDI Backup to disk [\\.pdvfs\BK1\2\BEData\STHVMDK]. Starting phase 1...

[6184] 07/10/13 09:10:23 [loops] - ValidatePDILocation: Validating PDI location: [\\.pdvfs\BK1\2\BEData\STHVMDK]. Temp path: [C:\TEMP]

[6184] 07/10/13 09:10:26 [loops] - BaseBSDProcessor::PDIGetPureDiskChangerDevice : Changer GUID : {FC18EEFE-6012-4E78-96FD-F34220209186}

[6184] 07/10/13 09:10:26 [loops] - Starting PDI Auto Expiry - Num of Images to expire: 1

[6184] 07/10/13 09:10:26 [loops] - PDI Auto Expiry done - Num of images actually expired: 0

[6184] 07/10/13 09:10:26 [loops] - Trying to create Restore BSD VMVCB::\\10.200.1.40\VCGuestVm\(DC)ha-datacenter(DC)\vm\FS1 for the PDI

[6184] 07/10/13 09:10:26 [server] - BackupMessageHandler::GetTargetDeviceHostName(): Execute(ADAMM_MOVER_EXECUTE_GET_SERVER_INFO) No server found.

[6184] 07/10/13 09:10:26 [loops] - NDMPAgentConnector:SetupConnection(): Data Server = BK1

[6184] 07/10/13 09:10:26 [ndmp\ndmpcomm] - Could not resolve the "bews-ndmp" or the "ndmp" service, error code: 10109, using port 10000

[6184] 07/10/13 09:10:26 [ndmp\ndmpcomm] - ndmpConnectEx: 'BK1' resolves to the local machine itself. So, we will try and connect to a loopback address ...

[6184] 07/10/13 09:10:26 [ndmp\ndmpcomm] - ndmpConnectEx : Control Connection information: A connection was established between end-points [::1]:58558 and [::1]:10000.

[6184] 07/10/13 09:10:26 [ndmp\ndmpclient] - NDMP version 3 connection CONNECTED

[6184] 07/10/13 09:10:26 [loops] - NDMPAgentConnector::AuthenticateClient(): Using SSPI authentication with SLA/DLA as a fallback

[6184] 07/10/13 09:10:26 [loops] - NDMPAgentConnector::ConnectAuthUseSSPIasDefault(): Attempting SSPI authentication...

[6184] 07/10/13 09:10:26 [ndmp\ndmpclient] - connectClientAuth(): agent is on local loopback, skipping SSL connection...

[6184] 07/10/13 09:10:26 [ndmp\ndmpcomm] - NDMP_SSPI: InitializeSecurityContext status 0x00090312 in 0 out 49

[6184] 07/10/13 09:10:26 [ndmp\ndmpcomm] - NDMP_SSPI: InitializeSecurityContext status 0x00000000 in 202 out 88

[6184] 07/10/13 09:10:26 [ndmp\ndmpcomm] - NDMP_SSPI: client authenticated with server

[6184] 07/10/13 09:10:26 [loops] - NDMPAgentConnector::ConnectAuthUseSSPIasDefault(): SSPI authentication success.

[6184] 07/10/13 09:10:26 [loops] - PDI backup - Starting data transfer between BK1 and BK1

[6184] 07/10/13 09:10:26 [loops] - DeviceIsNT4Server: agent info: [Major Version=6 Minor Version=1 Build Number=7601 ServicePack Major=1 ServicePack Minor=0 SuiteMask=274 ProductType=3 ProcessorType=AMD64].

[6184] 07/10/13 09:10:26 [loops] - DeviceIsIA64Server: agent info: [Major Version=6 Minor Version=1 Build Number=7601 ServicePack Major=1 ServicePack Minor=0 SuiteMask=274 ProductType=3 ProcessorType=AMD64].

[6184] 07/10/13 09:10:26 [loops] - Could not generate FFR queue. result=0x0

[6184] 07/10/13 09:10:27 [ndmp\ndmpclient] -

dataStartBackup: ndmpSendRequest returned: 0x0, 0

[6880] 07/10/13 09:10:32 [server] - Updating status for: 'VM Backup Test-VM Backup Test-VM Backup Test' (0x0 0xF)

[6880] 07/10/13 09:10:32 [server] - Status for: 'VM Backup Test-VM Backup Test-VM Backup Test' updated

[6184] 07/10/13 09:10:48 [server] - eng_msgs::stop_spec_op, Nothing to do...

[6880] 07/10/13 09:10:52 [server] - Updating status for: 'VM Backup Test-VM Backup Test-VM Backup Test' (0x0 0x0)

[6880] 07/10/13 09:10:52 [server] - Status for: 'VM Backup Test-VM Backup Test-VM Backup Test' updated

[6184] 07/10/13 09:11:15 [loops] - PDI: Received catalog add status update (dblks will be added to catalogs))

[6184] 07/10/13 09:11:15 [loops] - HandleSetMetaDataMessage() VM-MetaData: Received metadata for 'VMVCB::\\10.200.1.40\VCGuestVm\(DC)ha-datacenter(DC)\vm\FS1'. Snap: 'SYMC-DIFF 10-07-2013 09:10' Disks: 2 Change id: '564dd1f8-fd00-48a3-496c-d55ff4c8fffb(**)scsi0-0(*;)6000C29e-32d2-13fd-474e-a93a06e2baff(*;)52 c3 7b 0b 7b e6 85 47-60 ee 84 63 3e 9b d2 2c/108(**)scsi0-1(*;)6000C29d-f8f0-2e47-9261-d966552e31db(*;)52 bc bf cf 60 2f 01 12-c8 c9 1f 46 a6 28 b5 a5/108(**)' Chain: '564dd1f8-fd00-48a3-496c-d55ff4c8fffb(**)scsi0-0(*;)6000C29e-32d2-13fd-474e-a93a06e2baff(*;)*(**)scsi0-1(*;)6000C29d-f8f0-2e47-9261-d966552e31db(*;)*(**)'

[6184] 07/10/13 09:11:15 [loops] - PDI: Received pdi location (\\.pdvfs\BK1\2\BEData\STHVMDK\IMG001846) update)

[6184] 07/10/13 09:11:15 [loops] - notifyDataRead: Restore from PDI. Ignore the message...

[6880] 07/10/13 09:11:17 [server] - Updating status for: 'VM Backup Test-VM Backup Test-VM Backup Test' (0x1 0x0)

[6880] 07/10/13 09:11:17 [server] - Status for: 'VM Backup Test-VM Backup Test-VM Backup Test' updated

[6184] 07/10/13 09:11:17 [loops] - PDIBackupBSDProcessor::HandleMessage( ) - Ignoring the restore message : 0x00000003

[6184] 07/10/13 09:11:17 [loops] - PDI: ignore fhExtendedAddFile message from the backup side...

[6184] 07/10/13 09:11:22 [loops] - PDI: ignore fhExtendedAddFile message from the backup side...

[6184] 07/10/13 09:15:59 [loops] - PDI: ignore fhExtendedAddFile message from the backup side...

[6276] 07/10/13 09:25:07 [server] - DeviceManager: timeout event fired

[6276] 07/10/13 09:25:07 [server] - DeviceManager: processing pending requests

[6276] 07/10/13 09:25:07 [server] - DeviceManager: going to sleep for 900000 msecs

[6184] 07/10/13 09:30:40 [loops] - PDIBackupBSDProcessor::HandleMessage( ) - Ignoring the restore message : 0x0000000D

[6184] 07/10/13 09:30:40 [loops] - PDIBackupBSDProcessor::HandleMessage( ) - Ignoring the restore message : 0x0000000E

[6276] 07/10/13 09:40:07 [server] - DeviceManager: timeout event fired

[6276] 07/10/13 09:40:07 [server] - DeviceManager: processing pending requests

[6276] 07/10/13 09:40:07 [server] - DeviceManager: going to sleep for 900000 msecs

[6184] 07/10/13 09:41:19 [loops] - PDI: Received IPC object (BK1-VM-VCB-{5F1ECFA6-9EF1-4214-8272-B92B559FFCFC}) update)

[6184] 07/10/13 09:41:19 [loops] - PDI: Received request for additional phase (additional phase(data mining) required so catalogs will not be closed, on media server, Requires pdi dle, Shares ipc.)

[6184] 07/10/13 09:41:33 [loops] - data halted: SUCCESSFUL

[6184] 07/10/13 09:41:33 [loops] - BaseBSDProcessor::PollDataServer: Shutting down.

[6184] 07/10/13 09:41:37 [loops] - data halted: SUCCESSFUL

[6184] 07/10/13 09:41:37 [loops] - BaseBSDProcessor::PollDataServer: Shutting down.

[6184] 07/10/13 09:41:37 [loops] - PDI Backup to disk..starting phase 2 on media server...

[6184] 07/10/13 09:41:37 [loops] - PdvfsSyncAndUpdateDeDupeStats: PDVFSReaderSync succeeded.

[6184] 07/10/13 09:41:37 [loops] - PdvfsSyncAndUpdateDeDupeStats: Sucessfully gathered PDI Dedupe stats.

[6184] 07/10/13 09:41:38 [loops] - PDI backup: Starting catalog generation on server [BK1]

[6184] 07/10/13 09:41:38 [loops] - NDMPAgentConnector::EndConnection(): Data Server = BK1

[6184] 07/10/13 09:41:38 [loops] - Failed to Load AllowExcludes key, We will update DR file evenif there are userExcludes. Error: 5

[6184] 07/10/13 09:41:38 [loops] - NDMPAgentConnector:SetupConnection(): Data Server = BK1

[6184] 07/10/13 09:41:38 [ndmp\ndmpcomm] - Could not resolve the "bews-ndmp" or the "ndmp" service, error code: 10109, using port 10000

[6184] 07/10/13 09:41:38 [ndmp\ndmpcomm] - ndmpConnectEx: 'BK1' resolves to the local machine itself. So, we will try and connect to a loopback address ...

[6184] 07/10/13 09:41:38 [ndmp\ndmpcomm] - ndmpConnectEx : Control Connection information: A connection was established between end-points [::1]:64824 and [::1]:10000.

[6184] 07/10/13 09:41:38 [ndmp\ndmpclient] - NDMP version 3 connection CONNECTED

[6184] 07/10/13 09:41:38 [loops] - NDMPAgentConnector::AuthenticateClient(): Using SSPI authentication with SLA/DLA as a fallback

[6184] 07/10/13 09:41:38 [loops] - NDMPAgentConnector::ConnectAuthUseSSPIasDefault(): Attempting SSPI authentication...

[6184] 07/10/13 09:41:38 [ndmp\ndmpclient] - connectClientAuth(): agent is on local loopback, skipping SSL connection...

[6184] 07/10/13 09:41:38 [ndmp\ndmpcomm] - NDMP_SSPI: InitializeSecurityContext status 0x00090312 in 0 out 49

[6184] 07/10/13 09:41:38 [ndmp\ndmpcomm] - NDMP_SSPI: InitializeSecurityContext status 0x00000000 in 202 out 88

[6184] 07/10/13 09:41:38 [ndmp\ndmpcomm] - NDMP_SSPI: client authenticated with server

[6184] 07/10/13 09:41:38 [loops] - NDMPAgentConnector::ConnectAuthUseSSPIasDefault(): SSPI authentication success.

[6184] 07/10/13 09:41:38 [loops] - DeviceIsNT4Server: agent info: [Major Version=6 Minor Version=1 Build Number=7601 ServicePack Major=1 ServicePack Minor=0 SuiteMask=274 ProductType=3 ProcessorType=AMD64].

[6184] 07/10/13 09:41:38 [loops] - DeviceIsIA64Server: agent info: [Major Version=6 Minor Version=1 Build Number=7601 ServicePack Major=1 ServicePack Minor=0 SuiteMask=274 ProductType=3 ProcessorType=AMD64].

[6184] 07/10/13 09:41:38 [ndmp\ndmpclient] -

dataStartBackup: ndmpSendRequest returned: 0x0, 0

[6880] 07/10/13 09:41:42 [server] - Updating status for: 'VM Backup Test-VM Backup Test-VM Backup Test' (0x1 0x10)

[6880] 07/10/13 09:41:42 [server] - Status for: 'VM Backup Test-VM Backup Test-VM Backup Test' updated

[6184] 07/10/13 09:42:04 [loops] - PDI: Received catalog add status update (dblks will be added to catalogs))

[6184] 07/10/13 09:42:04 [server] - MSG_START_VIRTUAL_BACKUP_SET: StartShallowBackup():

[6184] 07/10/13 09:42:04 [server] - Volume Name : \\FS1.kkworx.local\C:

[6184] 07/10/13 09:42:04 [server] - Volume Label :

[6184] 07/10/13 09:42:04 [server] - Mount String : MountType: "4" OrigVolGUID: "Volume{73be0ad7-763b-11e1-ac3a-806e6f6e6963}" File: "0" Offset: "105906176" Letter: "C:"

[6184] 07/10/13 09:42:04 [server] - OS Id : 0x0E

[6184] 07/10/13 09:42:04 [server] - os Ver : 0x03

[6184] 07/10/13 09:42:04 [server] - Volume Size : 0xFFFFFFFF

[6184] 07/10/13 09:42:04 [server] - Vol Free Space : 0x85023000

[6184] 07/10/13 09:42:04 [server] - Vol Used Space : 0x7AFDCFFF

[6184] 07/10/13 09:42:04 [server] - MSG_START_VIRTUAL_BACKUP_SET: UpdateShallowbackupPDIFragInfo() - Segment Name: FS1-000001.vmdk; Relative Location: FS1\FS1-000001.vmdk; Segment Attribute: 0x2

[6184] 07/10/13 09:42:04 [loops] - BackupBSDProcessor::ExtendedAddFile: m_bVirtSet 1 m_virtDataId 14 m_virtBedsId 76 m_virtBedsVer 0

[6184] 07/10/13 09:43:29 [server] - MSG_END_VIRTUAL_BACKUP_SET: cat_build->FinishShallowBackup( ) succeeded.

[6184] 07/10/13 09:43:29 [server] - MSG_START_VIRTUAL_BACKUP_SET: StartShallowBackup():

[6184] 07/10/13 09:43:29 [server] - Volume Name : \\FS1.kkworx.local\D:

[6184] 07/10/13 09:43:29 [server] - Volume Label :

[6184] 07/10/13 09:43:29 [server] - Mount String : MountType: "4" OrigVolGUID: "Volume{2a4b3405-760f-11e1-96a8-000c29c8fffb}" File: "0" Offset: "1048576" Letter: "D:"

[6184] 07/10/13 09:43:29 [server] - OS Id : 0x0E

[6184] 07/10/13 09:43:29 [server] - os Ver : 0x03

[6184] 07/10/13 09:43:29 [server] - Volume Size : 0xFFFFFFFF

[6184] 07/10/13 09:43:29 [server] - Vol Free Space : 0x5F8E4000

[6184] 07/10/13 09:43:29 [server] - Vol Used Space : 0xA071BFFF

[6184] 07/10/13 09:43:29 [server] - MSG_START_VIRTUAL_BACKUP_SET: UpdateShallowbackupPDIFragInfo() - Segment Name: FS1_1-000001.vmdk; Relative Location: FS1\FS1_1-000001.vmdk; Segment Attribute: 0x2

[6184] 07/10/13 09:43:29 [loops] - BackupBSDProcessor::ExtendedAddFile: m_bVirtSet 1 m_virtDataId 14 m_virtBedsId 76 m_virtBedsVer 0

[6184] 07/10/13 09:45:00 [server] - MSG_END_VIRTUAL_BACKUP_SET: cat_build->FinishShallowBackup( ) succeeded.

[6184] 07/10/13 09:45:00 [server] - MSG_START_VIRTUAL_BACKUP_SET: StartShallowBackup():

[6184] 07/10/13 09:45:00 [server] - Volume Name : \\FS1.kkworx.local\Volume{73be0ad6-763b-11e1-ac3a-806e6f6e6963}

[6184] 07/10/13 09:45:00 [server] - Volume Label : System Reserved

[6184] 07/10/13 09:45:00 [server] - Mount String : MountType: "4" OrigVolGUID: "Volume{73be0ad6-763b-11e1-ac3a-806e6f6e6963}" File: "0" Offset: "1048576" Letter: "Volume{73be0ad6-763b-11e1-ac3a-806e6f6e6963}"

[6184] 07/10/13 09:45:00 [server] - OS Id : 0x0E

[6184] 07/10/13 09:45:00 [server] - os Ver : 0x03

[6184] 07/10/13 09:45:00 [server] - Volume Size : 0xFFFFFFFF

[6184] 07/10/13 09:45:00 [server] - Vol Free Space : 0x04BDE000

[6184] 07/10/13 09:45:00 [server] - Vol Used Space : 0xFB421FFF

[6184] 07/10/13 09:45:00 [server] - MSG_START_VIRTUAL_BACKUP_SET: UpdateShallowbackupPDIFragInfo() - Segment Name: FS1-000001.vmdk; Relative Location: FS1\FS1-000001.vmdk; Segment Attribute: 0x2

[6184] 07/10/13 09:45:00 [loops] - BackupBSDProcessor::ExtendedAddFile: m_bVirtSet 1 m_virtDataId 14 m_virtBedsId 76 m_virtBedsVer 0

[6184] 07/10/13 09:45:01 [server] - MSG_END_VIRTUAL_BACKUP_SET: cat_build->FinishShallowBackup( ) succeeded.

[6184] 07/10/13 09:45:01 [loops] - PDI: Received IPC object (BK1-VM-VCB-{5F1ECFA6-9EF1-4214-8272-B92B559FFCFC}) update)

[6184] 07/10/13 09:45:01 [loops] - PDI: Received request for additional phase (No additional phase required so catalogs will be closed, Invalid target server, does not require pdi dle, Does not share ipc.)

[6184] 07/10/13 09:45:41 [loops] - data halted: SUCCESSFUL

[6184] 07/10/13 09:45:41 [loops] - BaseBSDProcessor::PollDataServer: Shutting down.

[6184] 07/10/13 09:45:41 [loops] - PDI backup: Catalog generation done

[6184] 07/10/13 09:45:41 [server] - VM-MetaData: Backup of the resource VMVCB::\\10.200.1.40\VCGuestVm\(DC)ha-datacenter(DC)\vm\FS1 has failed(0) or canceled(0). Resetting the metadata. Disks: '2' to '0' Change id: '564dd1f8-fd00-48a3-496c-d55ff4c8fffb(**)scsi0-0(*;)6000C29e-32d2-13fd-474e-a93a06e2baff(*;)52 c3 7b 0b 7b e6 85 47-60 ee 84 63 3e 9b d2 2c/108(**)scsi0-1(*;)6000C29d-f8f0-2e47-9261-d966552e31db(*;)52 bc bf cf 60 2f 01 12-c8 c9 1f 46 a6 28 b5 a5/108(**)' to 'No change id' Chain: '564dd1f8-fd00-48a3-496c-d55ff4c8fffb(**)scsi0-0(*;)6000C29e-32d2-13fd-474e-a93a06e2baff(*;)*(**)scsi0-1(*;)6000C29d-f8f0-2e47-9261-d966552e31db(*;)*(**)' to 'No chain change id'

[6184] 07/10/13 09:45:41 [beutil] - FillRefCatBlob() VM-MetaData: Entered

[6184] 07/10/13 09:45:41 [beutil] - FillRefCatBlob() VM-MetaData: entered for loop

[6184] 07/10/13 09:45:41 [beutil] - FillRefCatBlob() VM-MetaData: modifying bsdMachineName = 10.200.1.40

[6184] 07/10/13 09:45:41 [beutil] - FillRefCatBlob() VM-MetaData: Directly before VMVCB check

[6184] 07/10/13 09:45:41 [beutil] - FillRefCatBlob() VM-MetaData: Saving metadata for 'VMVCB::\\10.200.1.40\VCGuestVm\(DC)ha-datacenter(DC)\vm\FS1'-'10.200.1.40'. Disks: 0 Change id: 'No change id' Chain: 'No chain change id'

[6184] 07/10/13 09:45:41 [server] - BackupMessageHandlerForBackupJob::process( eng_msgs::close_catalog & msg ) called

[6184] 07/10/13 09:45:41 [server] - Not: 'm_bCatalogDrivenBackup && CatBuildVector[engine_id] && GetCarryFwdCatalogInfoForRemainingObjs( )'

[6184] 07/10/13 09:45:41 [server] - called CatBuildVector[engine_id]->GetErrorCondition() successfully

[6184] 07/10/13 09:45:41 [server] - BackupMessageHandler::CDB_EndCurrentCatalogOperation( ) -- entered

[6184] 07/10/13 09:45:41 [server] - BackupMessageHandler::CDB_EndCurrentCatalogOperation( ) is calling PerBSDDataVector[engine_id]->EndCatOperation( )

[6184] 07/10/13 09:45:41 [server] - EndCatOperation succeeded

[6184] 07/10/13 09:45:41 [server] - BackupMessageHandler::CDB_EndCurrentCatalogOperation( ) -- returning

[6184] 07/10/13 09:45:41 [server] - calling CatBuildVector[engine_id]->FinishBackup( ) for non-cat drive backup

[6880] 07/10/13 09:45:42 [server] - Updating status for: 'VM Backup Test-VM Backup Test-VM Backup Test' (0x1 0x0)

[6880] 07/10/13 09:45:42 [server] - Status for: 'VM Backup Test-VM Backup Test-VM Backup Test' updated

[6184] 07/10/13 09:45:44 [loops] - PDI backup - done. result = 0

[6184] 07/10/13 09:45:44 [loops] - NDMPAgentConnector::EndConnection(): Data Server = BK1

[6184] 07/10/13 09:45:44 [tpfmt] - OST ===> Closing image.

[6184] 07/10/13 09:45:45 [tpfmt] - OST ===> Stats: PDDO Stats for (BK1): scanned: 0 KB, stream rate: 0.00 MB/sec, CR sent: 13 KB, dedup: 0.0%, cache hits: 0 (0.0%)

[6184] 07/10/13 09:45:45 [loops] - PDI DeDupe Stats: scanned: 0KB, stored: 0KB

[6184] 07/10/13 09:45:45 [tpfmt] - OST ===> Closing image.

[6184] 07/10/13 09:45:45 [tpfmt] - TF_PutChannel( ) 04A2C150

[6184] 07/10/13 09:45:45 [tpfmt] - TF_FreeDriveContext( 4D59D90 )

[6184] 07/10/13 09:45:45 [tpfmt] - TF_FreeTapeBuffers: from 2 to 0 buffers

[6184] 07/10/13 09:45:45 [tapealrt] - TAPEALERT: Get TapeAlert Flags Return Code = 0X0

[6184] 07/10/13 09:45:45 [tapealrt] - TAPEALERT: TapeAlert Device Flag = 0X0

[6184] 07/10/13 09:45:45 [tapealrt] - TAPEALERT: TapeAlert Changer Flag = 0X0

[6184] 07/10/13 09:45:45 [tapealrt] - TAPEALERT: Get TapeAlert Flags Return Code = 0X0

[6276] 07/10/13 09:45:45 [server] - DeviceManager: incoming event fired

[6276] 07/10/13 09:45:45 [server] - DeviceManager: Executing ReturnDeviceCall from thread 6184.

[6276] 07/10/13 09:45:51 [server] - DeviceManager: processing pending requests

[6276] 07/10/13 09:45:51 [server] - DeviceManager: going to sleep for 900000 msecs

[6276] 07/10/13 09:45:51 [server] - DeviceManager: dismount event fired

[6276] 07/10/13 09:45:51 [server] - DeviceManager: processing pending requests

[6276] 07/10/13 09:45:51 [server] - DeviceManager: going to sleep for 900000 msecs

[6184] 07/10/13 09:45:51 [server] - Removing 'VM Backup Test-VM Backup Test-VM Backup Test' from status update list

[6184] 07/10/13 09:45:51 [server] - Updating status for: 'VM Backup Test-VM Backup Test-VM Backup Test' (0x18 0x0)

[6184] 07/10/13 09:45:51 [server] - Status for: 'VM Backup Test-VM Backup Test-VM Backup Test' updated

[6184] 07/10/13 09:45:51 [server] - BackupJob::MergeBEVSRJobLogsIfNecessary: No VSR log file found, no merging necessary

[6184] 07/10/13 09:45:51 [server] - Ending job 'VM Backup Test-VM Backup Test-VM Backup Test' with error status (-536832647)

[6184] 07/10/13 09:45:51 [server] - Job thread terminating

ronnieshih · ‎07-10-2013

This seems to be the line that pinpoints the failure:

VM-MetaData: Backup of the resource VMVCB::\\10.200.1.40\VCGuestVm\(DC)ha-datacenter(DC)\vm\FS1 has failed(0) or canceled(0). Resetting the metadata. Disks: '2' to '0' Change id: '564dd1f8-fd00-48a3-496c-d55ff4c8fffb(**)scsi0-0(*;)6000C29e-32d2-13fd-474e-a93a06e2baff(*;)52 c3 7b 0b 7b e6 85 47-60 ee 84 63 3e 9b d2 2c/108(**)scsi0-1(*;)6000C29d-f8f0-2e47-9261-d966552e31db(*;)52 bc bf cf 60 2f 01 12-c8 c9 1f 46 a6 28 b5 a5/108(**)' to 'No change id' Chain: '564dd1f8-fd00-48a3-496c-d55ff4c8fffb(**)scsi0-0(*;)6000C29e-32d2-13fd-474e-a93a06e2baff(*;)*(**)scsi0-1(*;)6000C29d-f8f0-2e47-9261-d966552e31db(*;)*(**)' to 'No chain change id'

Now I noticed that the backup against this VM is failing and this is the only VM with 2 vmdk files which forms the c: and d: drives. It is not 1 volume with a logical partition. I know there are a few articles regarding 1 volume with multiple logical partitions, but this is not the case.

ronnieshih · ‎07-11-2013

BEREMOTE LOG, from beginning to end of the job,

[2412] 07/10/13 11:23:40 [push] - Opened debug log file C:\Program Files\Symantec\Backup Exec\RAWS\logs\FS1-beremote01.log

[2412] 07/10/13 11:23:40 [push] - Checking service rights and pending reboots.

[2412] 07/10/13 11:23:40 [push] - Checking for pending install reboot.

[2412] 07/10/13 11:23:40 [push] - Pending install reboot not detected.

[2412] 07/10/13 11:23:40 [push] - Checking to see if start up checks have been disabled.

[2412] 07/10/13 11:23:40 [push] - No start up checks have been disabled.

[2412] 07/10/13 11:23:40 [push] - Opening process token.

[2412] 07/10/13 11:23:40 [push] - Getting token SID.

[2412] 07/10/13 11:23:40 [push] - Got current SID: 'S-1-5-18'.

[2412] 07/10/13 11:23:40 [push] - Checking for local system account.

[2412] 07/10/13 11:23:40 [push] - Got local system SID: 'S-1-5-18'.

[2412] 07/10/13 11:23:40 [push] - Running as local system account. No more checks will be done.

[2412] 07/10/13 11:23:40 - Error accessing regkey: Software\Symantec\Backup Exec For Windows\Open File Option\ConfigOrphaned snaped can't be cleaned up. Maybe a privilage issue

[2412] 07/10/13 11:23:40 [besc] - CleanupOrphanedSnapshots(). Lauching cleanup thread..

[2412] 07/10/13 11:23:40 [besc] - CleanupOrphanedSnapshots(). Cleanup thread lauched. Exiting.

[0900] 07/10/13 11:23:40 [besc] - VssSnapshotVolume::CleanupOrphanedSnapshots(). No orphaned snaphots found

[4068] 07/10/13 11:23:41 [fsys\shared] - FS_InitFileSys

[4068] 07/10/13 11:23:41 [fsys\shared] - loaded bedsnt5.dll

[4068] 07/10/13 11:23:41 [fsys\shared] - bedsadc.dll could not be loaded: The specified module could not be found.

[4068] 07/10/13 11:23:41 [fsys\shared] - loaded bedssql2.dll

[4068] 07/10/13 11:23:41 [fsys\shared] - bedsxchg.dll could not be loaded: The specified module could not be found.

[4068] 07/10/13 11:23:42 [fsys\jet] - VirtApi DLL WAS LOADED FROM VirtApi.dll.

[4068] 07/10/13 11:23:42 [fsys\jet] - VirtApi DLL load check succeeded.

[4068] 07/10/13 11:23:42 [fsys\jet] - Virtual DB's WILL BE USED!

[4068] 07/10/13 11:23:42 [fsys\shared] - loaded bedsxese.dll

[4068] 07/10/13 11:23:42 [fsys\shared] - loaded bedsmbox.dll

[4068] 07/10/13 11:23:42 [fsys\shared] - bedspush.dll could not be loaded: The specified module could not be found.

[4068] 07/10/13 11:23:42 [fsys\shared] - loaded bedsnote.dll

[4068] 07/10/13 11:23:42 [fsys\shared] - loaded bedsmdoc.dll

[4068] 07/10/13 11:23:42 [fsys\shared] - loaded bedssps2.dll

[4068] 07/10/13 11:23:42 [fsys\shared] - loaded bedssps3.dll

[4068] 07/10/13 11:23:42 [fsys\shared] - loaded bedsupfs.dll

[4068] 07/10/13 11:23:42 [fsys\shared] - loaded bedsshadow.dll

[4068] 07/10/13 11:23:42 [fsys\shared] - loaded bedsoffhost.dll

[4068] 07/10/13 11:23:42 [fsys\shared] - bedsdpm.dll could not be loaded: The specified module could not be found.

[4068] 07/10/13 11:23:42 [fsys\shared] - loaded bedscps.dll

[4068] 07/10/13 11:23:42 [fsys\shared] - bedsvx.dll could not be loaded: The specified module could not be found.

[4068] 07/10/13 11:23:42 [fsys\shared] - bedsorcl.dll could not be loaded: The specified module could not be found.

[4068] 07/10/13 11:23:42 [fsys\shared] - loaded bedssmsp.dll

[4068] 07/10/13 11:23:42 [fsys\shared] - loaded bedsra.dll

[4068] 07/10/13 11:23:42 [fsys\shared] - loaded bedsrman.dll

[4068] 07/10/13 11:23:43 [fsys\shared] - loaded bedsdb2.dll

[4068] 07/10/13 11:23:43 [fsys\shared] - loaded bedsss.dll

[4068] 07/10/13 11:23:43 [fsys\jet] - VirtApi DLL WAS LOADED FROM VirtApi.dll.

[4068] 07/10/13 11:23:43 [fsys\jet] - VirtApi DLL load check succeeded.

[4068] 07/10/13 11:23:43 [fsys\jet] - Virtual DB's WILL BE USED!

[4068] 07/10/13 11:23:43 [fsys\shared] - loaded bedsadgran.dll

[4068] 07/10/13 11:23:43 [fsys\shared] - loaded bedsev.dll

[4068] 07/10/13 11:23:43 [beutil] - Failed to open EV Install key (SOFTWARE\KVS\Enterprise Vault\Install).

[4068] 07/10/13 11:23:43 [inc] - [AgentID:25] ... failed to load bedstrace.dll.

[4068] 07/10/13 11:23:43 [fsys\shared] - FS_DleGen: Failure to create debug trace object at line number 111

[4068] 07/10/13 11:23:43 [inc] - [AgentID:2a] ... failed to load bedstrace.dll.

[4068] 07/10/13 11:23:43 [fsys\shared] - FS_DleGen: Failure to create debug trace object at line number 111

[4068] 07/10/13 11:23:43 [fsys\shared] - loaded bedsvrtsrv.dll

[4068] 07/10/13 11:23:43 [fsys\shared] - loaded bedsvmvcb.dll

[4068] 07/10/13 11:23:43 [fsys\shared] - bedsspn.dll could not be loaded: The specified module could not be found.

[4068] 07/10/13 11:23:43 [fsys\shared] - loaded bedsNTFSArchive.dll

[4068] 07/10/13 11:23:43 [fsys\mb2] - MapiDll::Initialize() ... default MAPI32.DLL is loaded

[4068] 07/10/13 11:23:43 [fsys\mb2] - MapiDll::Initialize() ... failed to get 'MAPIInitialize' (0x7f)

[4068] 07/10/13 11:23:43 [fsys\shared] - loaded BedsExchMailArchival.dll

[4068] 07/10/13 11:23:43 [fsys\shared] - loaded bedsevm.dll

[4068] 07/10/13 11:23:43 [fsys\shared] - bedsdfsr.dll could not be loaded: The specified module could not be found.

[4068] 07/10/13 11:23:43 [fsys\shared] - Initializing FSs

[4068] 07/10/13 11:23:43 [fsys\ntfs] - Adding Windows 2008 files to move directly into place

[4068] 07/10/13 11:23:43 [fsys\mb2] - calling mapi initialize

[4068] 07/10/13 11:23:43 [fsys\mb2] - Mailbox: InitializeDAPI failed.

[4068] 07/10/13 11:23:43 [fsys\notes2] - Notes Agent:CLNPartitions::InitializeLNUCJWrapper

[4068] 07/10/13 11:23:43 [fsys\notes2] - Notes Agent:CLNPartitions::InitializeLNUCJWrapper - Exiting[0]

[4068] 07/10/13 11:23:43 [fsys\notes2] - Notes Agent:CLNPartitions::InitializeAllVolumes

[4068] 07/10/13 11:23:43 [fsys\notes2] - Notes Agent - CLNVolume::InitInstance - ReturnValue[0]

[4068] 07/10/13 11:23:43 [fsys\notes2] - Notes Agent:CLNPartitions::InitializeAllVolumes - Exiting[0]

[4068] 07/10/13 11:23:43 [fsys\notes2] - Notes Agent:CLNPartitions::InitInstance - Exiting[2]

[4068] 07/10/13 11:23:43 [fsys\oracle] - Function called: RMAN_InitFileSys

[4068] 07/10/13 11:23:43 [engidrapi] - IsIDRInProgressPriv: 0x0

[4068] 07/10/13 11:23:43 [fsys\shadow] - Informational: Initializing the BeDiskFind library 'BEDiskFind.dll' in SHADOW::InitBeDiskFindHelperApis

[4068] 07/10/13 11:23:43 [fsys\shadow] - Informational: BeDiskFind library 'BEDiskFind.dll' initialized in SHADOW::InitBeDiskFindHelperApis

[4068] 07/10/13 11:23:43 [fsys\shadow] - Informational: Initializing the BeDisk library 'BeDisk.dll' in SHADOW::InitBeDiskHelperApis

[4068] 07/10/13 11:23:43 [fsys\shadow] - Informational: BeDisk library 'BeDisk.dll' initialized in SHADOW::InitBeDiskHelperApis

[1980] 07/10/13 11:23:43 [fsys\mb2\edbprov] - Event: Global\RxService CREATED

[4068] 07/10/13 11:23:43 [fsys\ese] - first load attempt of esebcli2.dll failed: The specified module could not be found.

[4068] 07/10/13 11:23:43 [fsys\ese] - Looking for esebcli2.dll in sysetm path

[4068] 07/10/13 11:23:43 [fsys\ese] - never found EseBcli2.dll

[4068] 07/10/13 11:23:43 [fsys\ese] - esebcli2.dll not loaded

[4068] 07/10/13 11:23:43 [fsys\shared] - *** MSExchangeIS failed to get binary path

[4068] 07/10/13 11:23:43 [fsys\protsrvs\cps] - Status Unknown (0x00000002) opening Cps registry key 'Software\Symantec\Backup Exec CPS' in CPS::InitCpsHelperApis:376

[4068] 07/10/13 11:23:43 [fsys\protsrvs\cps] - Informational: Initializing the Cps library 'C:\Program Files\Symantec\Continuous Protection Server\Services\CPSVersion.dll' in CPS::InitCpsHelperApis:407

[4068] 07/10/13 11:23:43 [fsys\protsrvs\cps] - Status Unknown (0x0000007E) loading Cps library 'C:\Program Files\Symantec\Continuous Protection Server\Services\CPSVersion.dll' in CPS::InitCpsHelperApis:414

[4068] 07/10/13 11:23:43 [fsys\protsrvs\cps] - Status Unknown (0x0000007E) initializing Cps library in CPS::InitFsys:89

[4068] 07/10/13 11:23:43 [fsys\db2] - Function called: DB2_InitFileSys

[4068] 07/10/13 11:23:43 [beutil] - Input Error ( 0) for Type: (43)

[4068] 07/10/13 11:23:43 [fsys\ev] - Function called: EVM_InitFileSys

[4068] 07/10/13 11:23:43 [ndmp\ndmpsrvr] - Checking whether to initialize the tape server or not ...

[4068] 07/10/13 11:23:43 [ndmp\ndmpsrvr] - Win32AllowTapeServer: Could not open the key 'Software\Symantec\Backup Exec For Windows\Backup Exec\Tapeserver', error: 2

[4068] 07/10/13 11:23:43 [ndmp\ndmpsrvr] - QueryIfServiceIsPresent: OpenService( 'BackupExecDeviceMediaService' ) failed, error: 1060

[4068] 07/10/13 11:23:43 [ndmp\ndmpsrvr] - NDMPDMainThreadFunc: We are not part of a Media Server installation, so allowing the Tapeserver to initialize!

[4068] 07/10/13 11:23:44 [ndmp\ndmpcomm] - Could not resolve the "bews-ndmp" or the "ndmp" service, error code: 10109, using port 10000

[4068] 07/10/13 11:23:45 [BESocket] - @@@@@@@MyCloseSocket called with sockfd = 1040(0x410) retval = 0

[4068] 07/10/13 11:23:45 [BESocket] - @@@@@@@MyCloseSocket called with sockfd = 1036(0x40c) retval = 0

[4068] 07/10/13 11:23:45 [BESocket] - BETCPListener::BETCPListener: This system appears to be a Dual Stack system.

[4068] 07/10/13 11:23:45 [ndmp\ndmpcomm] - Started NDMP Listener on port 10000

[2412] 07/10/13 11:23:45 [writermanager] - IDS_INSTLIST_DEDUPE not installed

[2412] 07/10/13 11:23:45 [writermanager] - {ERROR} PDDE::StartWriterProcess() return=[0x80070490 UNKNOWN ERROR]

[2412] 07/10/13 11:23:45 [push] - Running... 'Q' to stop

[3960] 07/10/13 11:23:54 [ndmp\ndmpcomm] - NrdsAdvertiserThread: advertisement cycle started.

[3960] 07/10/13 11:23:54 [fsys\ntfs\mnet] - Informational: Restrict Anonymous Support is enabled

[3960] 07/10/13 11:23:54 [fsys\ntfs\mnet] - creating DLE for local machine

[3960] 07/10/13 11:23:54 [BESocket] - BENetConfigEx: Successfully refreshed adapter information.

[3960] 07/10/13 11:23:54 [fsys\ntfs\mnet] - EnumClusterDLEs: Could not opening cluster : The system could not find the environment option that was entered.

[3960] 07/10/13 11:23:54 [ndmp\ndmpcomm] - NrdsAdvertiserThread: EnumSelfDLE for file system 7 returned 0(0x0) and 1 DLEs

[3960] 07/10/13 11:23:54 [fsys\ese] - AreYouSureThisIsAnExchangeServer: FS1

[3960] 07/10/13 11:23:54 [fsys\ese] - AreYouSureThisIsAnExchangeServer FS1: 0

[3960] 07/10/13 11:23:54 [fsys\ese] - AreYouSureThisIsAnExchangeServer: FS1

[3960] 07/10/13 11:23:54 [fsys\ese] - AreYouSureThisIsAnExchangeServer FS1: 0

[3960] 07/10/13 11:23:54 [fsys\ese] - AreYouSureThisIsAnExchangeServer: FS1

[3960] 07/10/13 11:23:54 [fsys\ese] - AreYouSureThisIsAnExchangeServer FS1: 0

[3960] 07/10/13 11:23:54 [ndmp\ndmpcomm] - NrdsAdvertiserThread: Nrds Message Len : 6089.

[3960] 07/10/13 11:23:54 [fsys\oracle] - RMAN_EnumSelfDLE: AgentConfig GetOracleDBNames returned error. If Oracle Agent is installed, please run AgentConfig.

[3960] 07/10/13 11:23:54 [ndmp\ndmpcomm] - NrdsAdvertiserThread: EnumSelfDLE for file system 14 returned 0(0x0) and 0 DLEs

[3960] 07/10/13 11:23:54 [ndmp\ndmpcomm] - NrdsAdvertiserThread: EnumSelfDLE for file system 37 returned 0(0x0) and 0 DLEs

[3960] 07/10/13 11:23:54 [ndmp\ndmpcomm] - NrdsAdvertiserThread: EnumSelfDLE for file system 39 returned 0(0x0) and 0 DLEs

[3960] 07/10/13 11:23:54 [ndmp\ndmpcomm] - NrdsAdvertiserThread: EnumSelfDLE for file system 42 returned -536805816(0xE000FE48) and 0 DLEs

[3960] 07/10/13 11:23:54 [ndmp\ndmpcomm] - NrdsAdvertiserThread: Security is enabled!!!

[3960] 07/10/13 11:23:54 [ndmp\ndmpcomm] - GetCertificateDataFolderPath: Not checking for cluster.

[3960] 07/10/13 11:23:54 [nrds] - ConnectToServerEndPoint: dest=BK1, service=6101

[3960] 07/10/13 11:23:55 - SSL connection using version TLSv1

[3960] 07/10/13 11:23:55 - SSL connection using cipher AES256-SHA

[3960] 07/10/13 11:23:55 [nrds] - CreateConnection type=0 on socket 1204 via BESocket OK

[3960] 07/10/13 11:23:55 [ndmp\ndmpcomm] - NrdsAdvertiserThread: send of FS1.kkworx.local type 7 subtype 2 to target=BK1 port=6101 succeeded

[3960] 07/10/13 11:23:55 [BESocket] - @@@@@@@MyCloseSocket called with sockfd = 1204(0x4b4) retval = 0

[3960] 07/10/13 11:23:55 [ndmp\ndmpcomm] - NrdsAdvertiserThread: Security is enabled!!!

[3960] 07/10/13 11:23:55 [ndmp\ndmpcomm] - GetCertificateDataFolderPath: Not checking for cluster.

[3960] 07/10/13 11:23:55 [nrds] - ConnectToServerEndPoint: dest=BK1.kkworx.local, service=6101

[3960] 07/10/13 11:23:55 - SSL connection using version TLSv1

[3960] 07/10/13 11:23:55 - SSL connection using cipher AES256-SHA

[3960] 07/10/13 11:23:55 [nrds] - CreateConnection type=0 on socket 1232 via BESocket OK

[3960] 07/10/13 11:23:55 [ndmp\ndmpcomm] - NrdsAdvertiserThread: send of FS1.kkworx.local type 7 subtype 2 to target=BK1.kkworx.local port=6101 succeeded

[3960] 07/10/13 11:23:55 [BESocket] - @@@@@@@MyCloseSocket called with sockfd = 1232(0x4d0) retval = 0

[3960] 07/10/13 11:23:55 [ndmp\ndmpcomm] - NrdsAdvertiserThread: advertisement cycle complete. Waiting 240 minutes before advertising again.

[3128] 07/10/13 11:23:59 [ndmp\ndmpcomm] - NrdsAdvertiserThread: negative (purge) advertisement cycle started.

[3128] 07/10/13 11:23:59 [ndmp\ndmpcomm] - NrdsAdvertiserThread: no purge is pending.

[3128] 07/10/13 11:23:59 [ndmp\ndmpcomm] - NrdsAdvertiserThread: negative (purge) advertisement cycle complete. Waiting 240 minutes before advertising again.

[4068] 07/10/13 11:24:27 [ndmp\ndmpcomm] - ndmpRun: Control connection accepted : connection established between end-points [FE80::9195:66FB:76CB:8A11%11]:10000 and [FE80::484D:1A61:41C5:2848%11]:52437

[2800] 07/10/13 11:24:27 [ndmp\ndmpsrvr] - sslOpen() : Opening SSL for: 00000000DF7EC2AF

[2800] 07/10/13 11:24:27 [ndmp\ndmpsrvr] - sslOpen(): certinfo = 00000000DF84B1CF ; sslConn = 00000000DF84FA9F

[2800] 07/10/13 11:24:27 [ndmp\ndmpcomm] - GetCertificateDataFolderPath: Not checking for cluster.

[2800] 07/10/13 11:24:27 - SSL connection using version TLSv1

[2800] 07/10/13 11:24:27 - SSL connection using cipher AES256-SHA

[2800] 07/10/13 11:24:28 [ndmp\ndmpsrvr] - Username for Logon: KKWORX\administrator

[2800] 07/10/13 11:24:28 - BELogonUser: beclass::IsThisMe() returned error: 87

[2800] 07/10/13 11:24:28 - LogonType set = [LOGON32_LOGON_BATCH][0x4]

[2800] 07/10/13 11:24:28 - LogonUser(LOGON32_LOGON_BATCH-0x4) success

[2800] 07/10/13 11:24:28 - Successfully impersonated KKWORX\administrator

[2800] 07/10/13 11:24:28 - WhoAmI( ) reports: KKWORX\administrator

[2800] 07/10/13 11:24:28 [ndmp\ndmpsrvr] - LogonuserError: 0

[2800] 07/10/13 11:24:28 [ndmp\ndmpsrvr] - prep_for_full: The media server BK1.kkworx.local is already in the advertisement list.

[2800] 07/10/13 11:24:28 [ndmp\ndmpsrvr] - prep_for_full: The media server BK1 is already in the advertisement list.

[2800] 07/10/13 11:24:28 [engidrapi] - GetVirtualHardDisksNumbers() - Enter

[2800] 07/10/13 11:24:28 [engidrapi] - GetVirtualHardDisksNumbers() - Exit

[2800] 07/10/13 11:24:28 [fsys\ntfs] - GetServerType for local machine

[2800] 07/10/13 11:24:28 [engidrapi] - GetVirtualHardDisksNumbers() - Enter

[2800] 07/10/13 11:24:28 [engidrapi] - GetVirtualHardDisksNumbers() - Exit

[2800] 07/10/13 11:24:28 [fsys\ntfs] - GetServerType for local machine

[2800] 07/10/13 11:24:28 [fsys\ntfs\mnet] - Finding MNET entries using PunchDownWithWNetCalls()

[2800] 07/10/13 11:24:28 [fsys\notes2] - Notes Agent:FindDrives

[2800] 07/10/13 11:24:28 [fsys\oracle] - No Oracle SID's were discovered

[2800] 07/10/13 11:24:28 [fsys\ntfs] - GetServerType for local machine

[2800] 07/10/13 11:24:28 [fsys\shadow] - Device Shadow?Copy?Components Dle platform 2 major version 6 minor version 1 build 7601

[2800] 07/10/13 11:24:28 [fsys\upfs] - No utility partitions found on any of the disks

[2800] 07/10/13 11:24:28 [fsys\ra] - NRDS_RA_FindDrives entered

[2800] 07/10/13 11:24:28 [fsys\ra] - NRDS_RA_FindDrives completed immediately because we aren't browsing

[2800] 07/10/13 11:24:28 [fsys\protsrvs\cps] - Informational: Cps root device creation using default Cps library mechanism when creating device 'Cont?Prot?Srv' in CPS::DetermineRootCpsComponent:692

[2800] 07/10/13 11:24:28 [fsys\protsrvs\cps] - Informational: Cps library not available. Not creating Cps root device 'Cont?Prot?Srv' in CPS::DetermineRootCpsComponent:696

[2800] 07/10/13 11:24:28 [fsys\db2] - Function called: DB2_FindDrives

[2800] 07/10/13 11:24:28 [fsys\shared] - Status 0xE0008488 returned calling FindDrives for file system 28 in DLE_UpdateList

[2800] 07/10/13 11:24:28 [fsys\systemstate] - AD:DeviceName "System?State" in SystemState::CreateDLEs:373

[2800] 07/10/13 11:24:28 [fsys\systemstate] - AD:Full Device Path "System?State" in SystemState::CreateDLEs:378

[2800] 07/10/13 11:24:28 [fsys\systemstate] - AD:ADRO Agent is authorized for System?State.

[2800] 07/10/13 11:24:28 [fsys\systemstate] - AD:Found 0 instances of Active Directory Applcation Mode in SystemState::GetADAMInstanceCount:1415

[2800] 07/10/13 11:24:28 [fsys\ev] - EVM_FindDrives: Function called

[2800] 07/10/13 11:24:28 [fsys\ev] - EVM_FindDrives: Function Exit

[2800] 07/10/13 11:24:28 [fsys\sql2] - SQL2_FindDrives - the default SQL Service is not running on FS1.

[2800] 07/10/13 11:24:28 [fsys\ese] - [FSYS:ESE07] FindDrives ... This is not an Exchange Server (0)

[2800] 07/10/13 11:24:28 [beutil] - Input Error ( 0) for Type: (43)

[2800] 07/10/13 11:24:28 [fsys\shared] - FS_CreateTempDLE

[2800] 07/10/13 11:24:28 [fsys\shared] - 11 = 0xE000FE23

[2800] 07/10/13 11:24:28 [fsys\shared] - 12 = 0xE000FE23

[2800] 07/10/13 11:24:28 [fsys\notes2] - Notes Agent:CLNFileSystem::CreateTempDLE

[2800] 07/10/13 11:24:28 [fsys\notes2] - Notes Agent:CLNFileSystem::CreateTempDLE Exiting[-536805853]

[2800] 07/10/13 11:24:28 [fsys\shared] - 13 = 0xE000FE23

[2800] 07/10/13 11:24:28 [fsys\oracle] - RMAN_CreateTempDLE: Function called

[2800] 07/10/13 11:24:28 [fsys\oracle] - CheckIfNodeNameIsClusterName: Node name passed is FS1.kkworx.local

[2800] 07/10/13 11:24:28 [fsys\oracle] - CheckIfNodeNameIsClusterName: Server name converted is FS1

[2800] 07/10/13 11:24:28 [fsys\oracle] - CheckIfNodeNameIsClusterName: The node name passed for check is FS1

[2800] 07/10/13 11:24:28 [fsys\oracle] - CheckIfNodeNameIsClusterName:- The nodename passed is physical nodename.

[2800] 07/10/13 11:24:28 [fsys\oracle] - The node ( FS1 ) is physical node name.

[2800] 07/10/13 11:24:28 [fsys\shared] - 14 = 0xE000FE23

[2800] 07/10/13 11:24:28 [fsys\shared] - 16 = 0xE000FE23

[2800] 07/10/13 11:24:28 [fsys\shared] - 17 = 0xE000FE23

[2800] 07/10/13 11:24:28 [fsys\shared] - 18 = 0x00000001

[2800] 07/10/13 11:24:28 [fsys\ese] - CreateTempDLE: \\FS1.kkworx.local

[2800] 07/10/13 11:24:28 [fsys\shared] - 19 = 0xE00084AF

[2800] 07/10/13 11:24:28 [fsys\shared] - 20 = 0xE00084AF

[2800] 07/10/13 11:24:28 [fsys\shared] - 21 = 0xE00084AF

[2800] 07/10/13 11:24:28 [fsys\ohfs] - OFF_HOST_FS::OpenOHMetadataFile( :( error Opening the file (C:\Program Files\Symantec\Backup Exec\RAWS\Data\)

[2800] 07/10/13 11:24:28 [fsys\ohfs] - OFF_HOST_FS::GetDLEDetailsFromMDSrc() Status E_FS_OFF_HOST_DATA_CREATE_ERROR (E0000301) Opening the metadata source

[2800] 07/10/13 11:24:28 [fsys\ohfs] - OFF_HOST_FS::CreateTempDLE( ) Status E_FS_OFF_HOST_DATA_CREATE_ERROR (E0000301) creating Dle when creating temp Dle for device \\FS1.kkworx.local

[2800] 07/10/13 11:24:28 [fsys\shared] - 23 = 0xE0000301

[2800] 07/10/13 11:24:28 [fsys\shared] - 26 = 0x00000001

[2800] 07/10/13 11:24:28 [fsys\db2] - ====>DB2_CreateTempDLE

[2800] 07/10/13 11:24:28 [fsys\shared] - 28 = 0xE000FE23

[2800] 07/10/13 11:24:28 [fsys\systemstate] - AD:Device (\\FS1.kkworx.local) is not ours...

[2800] 07/10/13 11:24:28 [fsys\shared] - 30 = 0xE00084AF

[2800] 07/10/13 11:24:28 [fsys\shared] - 31 = 0xE00084AF

[2800] 07/10/13 11:24:28 [fsys\ese] - CreateTempDLE: \\FS1.kkworx.local

[2800] 07/10/13 11:24:28 [fsys\shared] - 35 = 0xE00084AF

[2800] 07/10/13 11:24:28 [fsys\shared] - 36 = 0xE00084AF

[2800] 07/10/13 11:24:28 [beutil] - ApplyRegExp(): Invalid input (\\FS1.kkworx.local). Parsing Failed.

[2800] 07/10/13 11:24:28 [beutil] - GoodEvName(): Invalid EV device (\\FS1.kkworx.local).

[2800] 07/10/13 11:24:28 [fsys\shared] - 37 = 0x00000001

[2800] 07/10/13 11:24:28 [fsys\vrtsrv] - VRTSRV:Device does not belong to us...(0xe00084af)

[2800] 07/10/13 11:24:28 [fsys\shared] - 38 = 0xE00084AF

[2800] 07/10/13 11:24:28 [fsys\vmvcb] - VM_VCBPROXY_FS::CreateTempDLE( ) Status DRIVE_DESCRIPTOR_ERROR (E000FE23) creating Dle when creating temp Dle for device \\FS1.kkworx.local

[2800] 07/10/13 11:24:28 [fsys\shared] - 39 = 0xE000FE23

[2800] 07/10/13 11:24:28 [beutil] - ApplyRegExp(): Invalid input (\\FS1.kkworx.local). Parsing Failed.

[2800] 07/10/13 11:24:28 [beutil] - GoodEvName(): Invalid EV device (\\FS1.kkworx.local).

[2800] 07/10/13 11:24:28 [fsys\shared] - 42 = 0x00000001

[2800] 07/10/13 11:24:28 [fsys\shared] - 45 = 0x00000001

[2800] 07/10/13 11:24:28 [fsys\shared] - 46 = 0xE00084AF

[2800] 07/10/13 11:24:28 [fsys\ntfs] - Not valid device name : \\FS1.kkworx.local

[2800] 07/10/13 11:24:28 [fsys\shared] - 47 = 0xE000FE23

[2800] 07/10/13 11:24:28 [fsys\ese] - CreateTempDLE: \\FS1.kkworx.local

[2800] 07/10/13 11:24:28 [fsys\shared] - 48 = 0xE00084AF

[2800] 07/10/13 11:24:28 [fsys\shared] - 5 = 0xE000FE23

[2800] 07/10/13 11:24:28 [fsys\ntfs\mnet] - no NRDS cache-hit for FS1.kkworx.local

[2800] 07/10/13 11:24:28 [fsys\ntfs\mnet] - Informational: Restrict Anonymous Support is enabled

[2800] 07/10/13 11:24:28 [fsys\ntfs\mnet] - creating DLE for local machine

[2800] 07/10/13 11:24:28 [fsys\shared] - 7 = 0x00000000

[2800] 07/10/13 11:24:28 [fsys\ntfs\mnet] - Finding MNET entries using MSNetFindLanManShares()

[2800] 07/10/13 11:24:28 [fsys\ntfs\mnet] - NTFS_SurrgateCalling: converted FS1.kkworx.local to FS1

[2800] 07/10/13 11:24:28 [fsys\ntfs\mnet] - Error 11001 opening cluster on FS1

[2800] 07/10/13 11:24:28 [fsys\ntfs\mnet] - Error 0 on NetShareEnum of \\FS1, level 1, entries 14, total 14

[2800] 07/10/13 11:24:28 [fsys\ntfs\mnet] - analyze excluded share -->ADMIN$<--

[2800] 07/10/13 11:24:28 [fsys\ntfs\mnet] - analyze admin / default share -->C$<--

[2800] 07/10/13 11:24:28 [fsys\ntfs\mnet] - adding share -->\\FS1.kkworx.local\C$<-- to the DLE list

[2800] 07/10/13 11:24:28 [fsys\ntfs\mnet] - analyze user share -->Common<--

[2800] 07/10/13 11:24:28 [fsys\ntfs\mnet] - adding share -->\\FS1.kkworx.local\Common<-- to the DLE list

[2800] 07/10/13 11:24:28 [fsys\ntfs\mnet] - analyze admin / default share -->D$<--

[2800] 07/10/13 11:24:28 [fsys\ntfs\mnet] - adding share -->\\FS1.kkworx.local\D$<-- to the DLE list

[2800] 07/10/13 11:24:28 [fsys\ntfs\mnet] - analyze user share -->Key Construction<--

[2800] 07/10/13 11:24:28 [fsys\ntfs\mnet] - adding share -->\\FS1.kkworx.local\Key Construction<-- to the DLE list

[2800] 07/10/13 11:24:28 [fsys\ntfs\mnet] - analyze user share -->Kiefer Insurance<--

[2800] 07/10/13 11:24:28 [fsys\ntfs\mnet] - adding share -->\\FS1.kkworx.local\Kiefer Insurance<-- to the DLE list

[2800] 07/10/13 11:24:28 [fsys\ntfs\mnet] - analyze excluded share -->print$<--

[2800] 07/10/13 11:24:28 [fsys\ntfs\mnet] - analyze user share -->Restricted<--

[2800] 07/10/13 11:24:28 [fsys\ntfs\mnet] - adding share -->\\FS1.kkworx.local\Restricted<-- to the DLE list

[2800] 07/10/13 11:24:28 [fsys\ntfs\mnet] - analyze user share -->User My Docs<--

[2800] 07/10/13 11:24:28 [fsys\ntfs\mnet] - adding share -->\\FS1.kkworx.local\User My Docs<-- to the DLE list

[2800] 07/10/13 11:24:28 [fsys\ntfs] - NTFS_SurrogateCalling: FS1.kkworx.local

[2800] 07/10/13 11:24:28 [fsys\ntfs] - Error opening cluster on FS1.kkworx.local: No such host is known.

[2800] 07/10/13 11:24:28 [fsys\ntfs] - Enumerating local drives

[2800] 07/10/13 11:24:28 [fsys\ntfs] - Creating DLEs:

[2800] 07/10/13 11:24:28 [fsys\ntfs] - \\FS1.kkworx.local\C:

[2800] 07/10/13 11:24:28 [engidrapi] - GetVirtualHardDisksNumbers() - Enter

[2800] 07/10/13 11:24:28 [engidrapi] - GetVirtualHardDisksNumbers() - Exit

[2800] 07/10/13 11:24:28 [fsys\ntfs] - GetServerType for local machine

[2800] 07/10/13 11:24:28 [fsys\ntfs] - \\FS1.kkworx.local\D:

[2800] 07/10/13 11:24:28 [engidrapi] - GetVirtualHardDisksNumbers() - Enter

[2800] 07/10/13 11:24:28 [engidrapi] - GetVirtualHardDisksNumbers() - Exit

[2800] 07/10/13 11:24:28 [fsys\ntfs] - GetServerType for local machine

[2800] 07/10/13 11:24:28 [fsys\ntfs] - \\FS1.kkworx.local\X:

[2800] 07/10/13 11:24:28 [fsys\notes2] - Notes Agent:CLNFileSystem::SurrogateCalling