VMware Communities: Message List - DS4000 SRM issues

Re: DS4000 SRM issues

FG0711 — Thu, 16 Jul 2009 20:18:44 GMT

Dex,

After studing your recent post, I tried the following:

1. Separated Controller A, port 2 of Protected storage and Controller A, por2 of recovery storage into one zone and Controller B, p2 of protected storage and Controller B, port2 of recovery storage into a different zone. Both zones are on the same VSAN.

2. Above resulted in inability to set up a mirrored pair. I get an error message - saying can not esablish communication to the other side of a mirrored pair

Therefore, I had to combied all for FC ports in (1) into the same zone.

I understnd that may have created a problem of a controller failover I've seen, but the system still works OK .

I tested failover sevaral times and everything looks good. Thanks again for your very usefull comments.

Re: DS4000 SRM issues

FG0711 — Mon, 13 Jul 2009 15:42:52 GMT

Dex_1234,

Thanks again for your detailed post. Even though I now have SRM working, I am looking into my fabric connections to see why sometimes both of my SANs switch from one controller to another one. We were forced to implement a redundant fabric using two Cisco MDS9124 switches on each side, but then connected them into a single fabric by connecting the fabric into a single one at the Protected side to accomodate DS4700-70 situation ( one available port per controller with replication on). This was suggested by a post here earlier.

Other small issues I would like to understand are:

1. It looks like SRM adds a UUID number in front of the datastore name assigned for recovery: srm_datastore -> uuid_srm_datasore.

2. It looks like SRM initiates a reverse replication once the failover is complete and the new protected site is up.

I would like to keep my name assignments and not to start replication in the opposite direction automatically.

I would appreciate any feedback, Thanks

Re: DS4000 SRM issues

dex_1234 — Thu, 09 Jul 2009 18:55:55 GMT

The problems you're seeing during the protection group configuration and with datastore access may have been caused by the fact that you had a logical drive failover event occurring around 8:31 AM. The MEL log from "SAN2"
shows a mode select event(seq #1460, event#300D), this indicates that the ESX failover driver issued a lun failover request to controller A. Shortly thereafter we get the infamous "logical drive not on preferred path entry". I dug a little
deeper and it looks like the request came specifically from HBA port 2100001b32049edf on ESX2. For some reason the alternate HBA port lost communication with the storage subsystem at this point in time(*2100001b3204a0df* )

And if you look at the corresponding time frame in your vmware-dr log, it seems this is when SRM begins to start having issues:

2009-07-09 08:30:16.531 'RemoteSite 'Protected Site'' 3596 info Raising RemoteSitePingFailed event
2009-07-09 08:30:16.531 'RemoteSite 'Protected Site'' 3416 info Attempting to reconnect
2009-07-09 08:30:16.531 'RemoteSite 'Protected Site'' 3416 info Attempting to connect to remote site
2009-07-09 08:30:16.578 'LicenseManager' 3580 info FlexLM: The feature 'SRM_PROTECTED_HOST' is not present on the license server or has expired.
2009-07-09 08:30:17.515 'RemoteSite 'Protected Site'' 3416 warning Failed to connect to remote DR: Unexpected Vmacore::SystemException No connection could be made because the target machine actively refused it. (10061)
2009-07-09 08:31:16.484 'LocalSiteStatus' 3416 verbose Free disk space: 129438 Mb
2009-07-09 08:31:16.484 'LocalSiteStatus' 3416 verbose CPU usage: 1 %
2009-07-09 08:31:16.484 'LocalSiteStatus' 3416 verbose Available memory: 3462 Mb
2009-07-09 08:31:16.531 'RemoteSite 'Protected Site'' 3416 warning Failed to ping remote site
2009-07-09 08:31:17.515 'RemoteSite 'Protected Site'' 3580 info Attempting to reconnect
2009-07-09 08:31:17.515 'RemoteSite 'Protected Site'' 3580 info Attempting to connect to remote site
2009-07-09 08:31:18.593 'RemoteSite 'Protected Site'' 3580 warning Failed to connect to remote DR: Unexpected Vmacore::SystemException No connection could be made because the target machine actively refused it. (10061)
2009-07-09 08:32:16.484 'LocalSiteStatus' 3596 verbose Free disk space: 129438 Mb
2009-07-09 08:32:16.484 'LocalSiteStatus' 3596 verbose CPU usage: 0 %
2009-07-09 08:32:16.484 'LocalSiteStatus' 3596 verbose Available memory: 3461 Mb
2009-07-09 08:32:16.531 'RemoteSite 'Protected Site'' 3596 warning Failed to ping remote site
2009-07-09 08:32:18.593 'RemoteSite 'Protected Site'' 3576 info Attempting to reconnect
2009-07-09 08:32:18.593 'RemoteSite 'Protected Site'' 3576 info Attempting to connect to remote site
2009-07-09 08:32:19.515 'RemoteSite 'Protected Site'' 3576 warning Failed to connect to remote DR: Unexpected Vmacore::SystemException No connection could be made because the target machine actively refused it. (10061)
2009-07-09 08:33:16.484 'LocalSiteStatus' 3576 verbose Free disk space: 129438 Mb
2009-07-09 08:33:16.484 'LocalSiteStatus' 3576 verbose CPU usage: 0 %
2009-07-09 08:33:16.484 'LocalSiteStatus' 3576 verbose Available memory: 3457 Mb
2009-07-09 08:33:16.531 'RemoteSite 'Protected Site'' 3576 info Raising RemoteSiteDown event
2009-07-09 08:33:19.515 'RemoteSite 'Protected Site'' 3416 info Attempting to reconnect
2009-07-09 08:33:19.515 'RemoteSite 'Protected Site'' 3416 info Attempting to connect to remote site
2009-07-09 08:33:25.140 'RemoteSite 'Protected Site'' 3416 info VC Connection: Logging in as user 'administrator'
2009-07-09 08:33:25.203 'RemoteSite 'Protected Site'' 3416 info VC Connection: Logged in session 6343D5BF-3917-469F-ABBA-3ACDC4A290AB
2009-07-09 08:33:26.140 'RemoteSite 'Protected Site'' 3416 warning Failed to connect to remote DR: Unexpected exception 'class Vmacore::Http::HttpException' HTTP error response: Service Unavailable
2009-07-09 08:33:26.140 'RemoteSite 'Protected Site'' 3416 verbose VC Connection: Logging out session 6343D5BF-3917-469F-ABBA-3ACDC4A290AB
2009-07-09 08:33:26.203 'RemoteSite 'Protected Site'' 3416 verbose VC Connection: Logged out session 6343D5BF-3917-469F-ABBA-3ACDC4A290AB
2009-07-09 08:34:16.484 'LocalSiteStatus' 3596 verbose Free disk space: 129435 Mb
2009-07-09 08:34:16.484 'LocalSiteStatus' 3596 verbose CPU usage: 3 %
2009-07-09 08:34:16.484 'LocalSiteStatus' 3596 verbose Available memory: 3416 Mb
2009-07-09 08:34:16.531 'RemoteSite 'Protected Site'' 3596 warning Failed to ping remote site
2009-07-09 08:34:16.578 'LicenseManager' 3596 verbose FlexLM: Server Available.
2009-07-09 08:34:16.578 'LicenseManager' 3596 info FlexLM: The feature 'SRM_PROTECTED_HOST' is not present on the license server or has expired.
2009-07-09 08:34:16.640 'HostLicenseMonitor' 3596 verbose Checking Host Licenses

I'm not sure what caused the initial failover, but make sure you're following the multi-pathing guidelines laid out by vmware for ds storage and if you haven't done so already redistribute the logical drives back to its original controller via storagemanager.

Re: DS4000 SRM issues

FG0711 — Thu, 09 Jul 2009 14:38:46 GMT

dex, i have the LUNs synchronized now. i will try to follow your document for a test failover now

Re: DS4000 SRM issues

dex_1234 — Thu, 09 Jul 2009 14:15:07 GMT

I was just trying to understand where you where at in your testing. As for the logs I'm just trying to correlate the srm logs with activities on the storage system, I'm mainly looking at your MEL log in the bundle.

Re: DS4000 SRM issues

FG0711 — Thu, 09 Jul 2009 14:06:40 GMT

attached. What is that I should be looking for in the logfiles ? thanks

Re: DS4000 SRM issues

FG0711 — Thu, 09 Jul 2009 14:05:30 GMT

dex_1234,

i did not do a failback after my first failover testing the other day. I deleted all data from the failover datastore, snap shot and re-created the test VM.

logfiles attached, another file is in the next post

Re: DS4000 SRM issues

dex_1234 — Thu, 09 Jul 2009 13:39:51 GMT

Starting and stopping the replication to create a protection group is not normal. Initial setup and during a failback event after SRM failover are times when replication would have to be administered. Also, how did you perform
the failback procedure(in regards to replication) earlier in your testing? Did you remove the mirror relationship and then re-establish it going in the other direction or did you reverse the roles? Also, can you post your storage subsystem support bundle as well?(storage manager: advance->troubleshooting->collect)

regards, dex

Re: DS4000 SRM issues

FG0711 — Thu, 09 Jul 2009 13:14:25 GMT

Masha,

After ESX restart I did not see that error. However, I got another one : unable to create a virtual machine ......unable to . access datastore ........ in the recovery site. I had to stop replication of the LUN, create the protection group and then re- start replication again. Is that normal ? I do not remember seeing it in SRM admin manual. The recovery site log is below. I am now waiting for replication to complete to try the failover again. Thanks for feedback - felix

++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++

Log for VMware Site Recovery Manager, pid=2072, version=1.0.1, build=build-128004, option=Release, section=2
~~2009-07-09 08:29:04.250 'App' 2076 warning~~ Failed to create console writer
~~2009-07-09 08:29:04.281 'App' 2100 info~~ Set dump dir to 'C:\Documents and Settings\All Users\Application Data\VMware\VMware Site Recovery Manager\DumpFiles'
~~2009-07-09 08:29:04.281 'App' 2100 info~~ Intializing the DBManager
~~2009-07-09 08:29:11.718 'App' 2100 info~~ Current working directory: C:\Program Files\VMware\VMware Site Recovery Manager\bin
~~2009-07-09 08:29:11.718 'ThreadPool' 2100 verbose~~ TaskMax=10, IoMin=1, IoMax=21
~~2009-07-09 08:29:11.718 'App' 2100 info~~ Trying DrExternalRecoveryApi
~~2009-07-09 08:29:11.718 'App' 2100 verbose~~ Plugin 0 path: dr-external-recovery-api.dll
~~2009-07-09 08:29:11.718 'App' 2100 verbose~~ Plugin 0 absolute path: C:\Program Files\VMware\VMware Site Recovery Manager\bin\dr-external-recovery-api.dll
~~2009-07-09 08:29:11.718 'App' 2100 info~~ Trying RecoverySecondary
~~2009-07-09 08:29:11.718 'App' 2100 verbose~~ Plugin 1 path: dr-secondary-recovery.dll
~~2009-07-09 08:29:11.718 'App' 2100 verbose~~ Plugin 1 absolute path: C:\Program Files\VMware\VMware Site Recovery Manager\bin\dr-secondary-recovery.dll
~~2009-07-09 08:29:11.718 'App' 2100 info~~ Trying SanProvider
~~2009-07-09 08:29:11.718 'App' 2100 verbose~~ Plugin 2 path: dr-san-provider.dll
~~2009-07-09 08:29:11.718 'App' 2100 verbose~~ Plugin 2 absolute path: C:\Program Files\VMware\VMware Site Recovery Manager\bin\dr-san-provider.dll
~~2009-07-09 08:29:11.718 'App' 2100 info~~ Trying TestProvider
~~2009-07-09 08:29:11.718 'App' 2100 verbose~~ Plugin 3 path: dr-test-provider.dll
~~2009-07-09 08:29:11.718 'App' 2100 verbose~~ Plugin 3 absolute path: C:\Program Files\VMware\VMware Site Recovery Manager\bin\dr-test-provider.dll
~~2009-07-09 08:29:11.718 'SrmServiceInstance' 2100 info~~ DrExtApi Service Instance is initialized.
~~2009-07-09 08:29:11.718 'DrExternalRecoveryApi' 2100 info~~ Plugin started.
~~2009-07-09 08:29:11.718 'SanProvider' 2100 info~~ Provider 'SanProvider' has MoRef 'dr.primary.SanReplicationProvider:PrimarySanProvider'.
~~2009-07-09 08:29:11.718 'Replication' 2100 info~~ Registered provider 'SanProvider'
~~2009-07-09 08:29:11.718 'SanProvider' 2100 info~~ Provider 'SanProvider' has MoRef 'dr.secondary.SanReplicationProvider:SecondarySanProvider'.
~~2009-07-09 08:29:11.718 'SecondaryReplication' 2100 info~~ Registered provider 'SanProvider'
~~2009-07-09 08:29:11.718 'SanProvider' 2100 info~~ Plugin started.
~~2009-07-09 08:29:11.718 'TestProvider' 2100 info~~ Provider 'TestProvider' has MoRef 'dr.PrimaryTestProvider:primary-test-provider'.
~~2009-07-09 08:29:11.718 'Replication' 2100 info~~ Registered provider 'TestProvider'
~~2009-07-09 08:29:11.718 'TestProvider' 2100 info~~ Provider 'TestProvider' has MoRef 'dr.SecondaryTestProvider:secondary-test-provider'.
~~2009-07-09 08:29:11.718 'SecondaryReplication' 2100 info~~ Registered provider 'TestProvider'
~~2009-07-09 08:29:11.718 'TestProvider' 2100 info~~ Plugin started.
~~2009-07-09 08:29:13.062 'DrServiceInstance' 2100 info~~ LocalSite already installed - Good!
~~2009-07-09 08:29:14.468 'App' 2100 info~~ Vmacore::InitSSL: doVersionCheck = true, handshakeTimeoutUs = 120000000
~~2009-07-09 08:29:16.421 'MainVcConnection' 2100 info~~ VC Connection: Logging in as user 'administrator'
~~2009-07-09 08:29:16.453 'MainVcConnection' 2100 info~~ VC Connection: Logged in session 38C56EA7-2CD2-4FDC-B261-087BB1512599
~~2009-07-09 08:29:16.468 'LocalSiteStatus' 2100 info~~ Minimum free disk space: 100 Mb
~~2009-07-09 08:29:16.468 'LocalSiteStatus' 2100 info~~ Maximum CPU usage: 80 %
~~2009-07-09 08:29:16.468 'LocalSiteStatus' 2100 info~~ Minimum available memory: 32 Mb
~~2009-07-09 08:29:16.468 'LocalSiteStatus' 2100 info~~ Check interval: 60 sec
~~2009-07-09 08:29:16.468 'LocalSiteStatus' 2100 info~~ Event frequency: 600 sec
~~2009-07-09 08:29:16.484 'LocalSiteStatus' 2100 info~~ Started monitoring local site
~~2009-07-09 08:29:16.484 'DrServiceInstance' 2100 info~~ Loading remote sites from database...
~~2009-07-09 08:29:16.484 'LocalSiteStatus' 3580 verbose~~ Free disk space: 129438 Mb
~~2009-07-09 08:29:16.484 'LocalSiteStatus' 3580 verbose~~ CPU usage: 0 %
~~2009-07-09 08:29:16.484 'LocalSiteStatus' 3580 verbose~~ Available memory: 3468 Mb
~~2009-07-09 08:29:16.515 'DrInventoryMapper: site-400' 2100 info~~ Created Inventory Mapper for site 'site-400'
~~2009-07-09 08:29:16.515 'RemoteSite 'Protected Site'' 2100 warning~~ Configuration parameter checkInterval is not specified
~~2009-07-09 08:29:16.515 'RemoteSite 'Protected Site'' 2100 info~~ Check interval: 60 sec
~~2009-07-09 08:29:16.515 'RemoteSite 'Protected Site'' 2100 warning~~ Configuration parameter warningDelay is not specified
~~2009-07-09 08:29:16.515 'RemoteSite 'Protected Site'' 2100 info~~ Time delay before raising low priority event: 120 sec
~~2009-07-09 08:29:16.515 'RemoteSite 'Protected Site'' 2100 warning~~ Configuration parameter panicDelay is not specified
~~2009-07-09 08:29:16.515 'RemoteSite 'Protected Site'' 2100 info~~ Time delay before raising high priority event: 300 sec
~~2009-07-09 08:29:16.515 'RemoteSite 'Protected Site'' 2100 warning~~ Configuration parameter panicRepeatDelay is not specified
~~2009-07-09 08:29:16.515 'RemoteSite 'Protected Site'' 2100 info~~ Time delay before raising repeated high priority event: 300 sec
~~2009-07-09 08:29:16.515 'RemoteSite 'Protected Site'' 2100 info~~ Attempting to connect to remote site
~~2009-07-09 08:29:16.515 'RemoteSite 'Protected Site'' 2100 warning~~ Wait authorization manager to wake up!
~~2009-07-09 08:29:16.531 'RemoteSite 'Protected Site'' 2100 warning~~ Failed to connect to remote site: Unexpected MethodFault (dr.fault.InvalidState) {
dynamicType = <unset>,
msg = ""
}
~~2009-07-09 08:29:16.531 'RemoteSite 'Protected Site'' 3580 warning~~ Received notification of broken DR connection
~~2009-07-09 08:29:16.531 'RemoteSite 'Protected Site'' 3580 warning~~ Failed to ping remote site
~~2009-07-09 08:29:16.531 'RemoteSite 'Protected Site'' 3580 info~~ Attempting to reconnect
~~2009-07-09 08:29:16.531 'RemoteSite 'Protected Site'' 3580 info~~ Attempting to connect to remote site
~~2009-07-09 08:29:16.531 'RemoteSite 'Protected Site'' 3580 warning~~ Wait authorization manager to wake up!
~~2009-07-09 08:29:16.531 'RemoteSite 'Protected Site'' 3596 warning~~ Received notification of broken VC connection
~~2009-07-09 08:29:16.531 'RemoteSite 'Protected Site'' 3580 warning~~ Failed to connect to remote DR: Unexpected MethodFault (dr.fault.InvalidState) {
dynamicType = <unset>,
msg = ""
}
~~2009-07-09 08:29:16.546 'LicenseManager' 2100 info~~ Changing to state: DrLicensedState
~~2009-07-09 08:29:16.578 'LicenseManager' 2100 info~~ FlexLM: Created license job with server '27000@vcs2'
~~2009-07-09 08:29:16.578 'LicenseManager' 2100 info~~ FlexLM: The feature 'SRM_PROTECTED_HOST' is not present on the license server or has expired.
~~2009-07-09 08:29:16.593 'LicenseManager' 2100 verbose~~ FlexLM: Checked out license 'PROD_SRM', count: 1, total: 1, avail: 4 pending: 0, daysLeft: 3650000
~~2009-07-09 08:29:16.593 'LicenseManager' 2100 verbose~~ FlexLM: Checked out license 'PROD_SRM', count: 1, total: 1, avail: 4 pending: 0, daysLeft: 3650000
~~2009-07-09 08:29:16.640 'DrPrimaryConfig' 2100 info~~ Configuration initialized
~~2009-07-09 08:29:16.671 'PrimarySanProvider' 2100 verbose~~ Loading Primary::SanProvider from DB object
~~2009-07-09 08:29:16.687 'SanProviderConfig' 2100 info~~ Using scripts from 'C:\Program Files\VMware\VMware Site Recovery Manager\scripts\SAN\'
~~2009-07-09 08:29:16.687 'SanProviderConfig' 2100 info~~ Using temporary directory 'C:\WINDOWS\TEMP\vmware-SYSTEM'
~~2009-07-09 08:29:16.687 'SanProviderConfig' 2100 info~~ Using script interpreter 'C:\Program Files\VMware\VMware Site Recovery Manager\external\perl-5.8.8\bin\perl.exe'
~~2009-07-09 08:29:16.687 'SanProviderConfig' 2100 info~~ Using 'command.pl' to launch scripts
~~2009-07-09 08:29:16.687 'SanProviderConfig' 2100 info~~ Setting script executing timeout to 300 seconds
~~2009-07-09 08:29:16.687 'SanProviderConfig' 2100 info~~ Setting array sync frequency to 86400 seconds
~~2009-07-09 08:29:16.687 'SanProviderConfig' 2100 info~~ Setting minimum interval between LUN Group computations to 0 seconds
~~2009-07-09 08:29:16.687 'SanProviderConfig' 2100 info~~ Setting number of repeated host rescans during recovery to 1
~~2009-07-09 08:29:16.687 'SanProviderConfig' 2100 info~~ Setting timeout for host rescan task to 1200 seconds
~~2009-07-09 08:29:16.687 'SanProviderConfig' 2100 info~~ Setting timeout for host reconnect to 60 seconds
~~2009-07-09 08:29:16.687 'SanProviderConfig' 2100 info~~ Setting timeout for VC tasks to 300 seconds
~~2009-07-09 08:29:16.687 'SanProviderConfig' 2100 info~~ Setting Fix Recovered Datastore Names flag to 'OFF'
~~2009-07-09 08:29:16.687 'PrimarySanProvider' 2100 verbose~~ Processing config folder 'C:/Program Files/VMware/VMware Site Recovery Manager/scripts/SAN/IBM'
~~2009-07-09 08:29:16.687 'PrimarySanProvider' 2100 verbose~~ Loading management system 'IBM-DS4xxx/DS5xxx-Native'
~~2009-07-09 08:29:16.687 'PrimarySanProvider' 2100 trivia~~ (dr.san.ManagementSystemConfig) {
dynamicType = <unset>,
name = "IBM-DS4xxx/DS5xxx-Native",
manageMultiple = false,
connectionInfo = (dr.san.ConnectionInfo) [
(dr.san.ConnectionInfo) {
dynamicType = <unset>,
name = "DS4800",
passwordAuthRequired = (not shown),
securityFileRequired = false,
addressLabel = (string) [
"IP1",
"IP2"
],
}
],
modelSupportInfo = (dr.san.ModelSupportInfo) [
(dr.san.ModelSupportInfo) {
dynamicType = <unset>,
product = "1818 FastT",
model = "DS5000 Series",
command = (dr.san.ModelSupportInfo.Command) [
"discoverArrays",
"discoverLuns",
"testFailover",
"failover"
],
},
(dr.san.ModelSupportInfo) {
dynamicType = <unset>,
product = "1815 FAStT",
model = "DS4800",
command = (dr.san.ModelSupportInfo.Command) [
"discoverArrays",
"discoverLuns",
"testFailover",
"failover"
],
},
(dr.san.ModelSupportInfo) {
dynamicType = <unset>,
product = "1814 200FAStT",
model = "DS4200",
command = (dr.san.ModelSupportInfo.Command) [
"discoverArrays",
"discoverLuns",
"testFailover",
"failover"
],
},
(dr.san.ModelSupportInfo) {
dynamicType = <unset>,
product = "1814 FAStT",
model = "DS4700",
command = (dr.san.ModelSupportInfo.Command) [
"discoverArrays",
"discoverLuns",
"testFailover",
"failover"
],
}
],
configDirectory = "C:/Program Files/VMware/VMware Site Recovery Manager/scripts/SAN/IBM",
}
~~2009-07-09 08:29:16.687 'PrimarySanProvider' 2100 verbose~~ Loading Storage Manager 'storage-manager-7' from DB object
~~2009-07-09 08:29:16.687 'PrimarySanProvider' 2100 verbose~~ Storage Manager 'storage-manager-7' reconstructed from database
~~2009-07-09 08:29:16.687 'PrimarySanProvider' 2100 verbose~~ Primary::SanProvider reconstructed from database
~~2009-07-09 08:29:16.703 'Replication' 2100 verbose~~ Loading ReplicationManager from DB object
~~2009-07-09 08:29:16.703 'Replication' 2100 verbose~~ Loading 0 protection profiles from database
~~2009-07-09 08:29:16.703 'PrimarySanProvider' 2100 info~~ SAN provider started
~~2009-07-09 08:29:16.703 'Recovery' 2100 info~~ Maximum LROs on VC is 16
~~2009-07-09 08:29:16.703 'Recovery' 2100 info~~ RecoveryManagerImpl Created
~~2009-07-09 08:29:16.703 'DrSecondaryConfig' 2100 info~~ Configuration initialized
~~2009-07-09 08:29:16.734 'SecondarySanProvider' 2100 verbose~~ Loading Secondary::SanProvider from DB object
~~2009-07-09 08:29:16.734 'SecondarySanProvider' 2100 verbose~~ Processing config folder 'C:/Program Files/VMware/VMware Site Recovery Manager/scripts/SAN/IBM'
~~2009-07-09 08:29:16.734 'SecondarySanProvider' 2100 verbose~~ Loading management system 'IBM-DS4xxx/DS5xxx-Native'
~~2009-07-09 08:29:16.734 'SecondarySanProvider' 2100 trivia~~ (dr.san.ManagementSystemConfig) {
dynamicType = <unset>,
name = "IBM-DS4xxx/DS5xxx-Native",
manageMultiple = false,
connectionInfo = (dr.san.ConnectionInfo) [
(dr.san.ConnectionInfo) {
dynamicType = <unset>,
name = "DS4800",
passwordAuthRequired = (not shown),
securityFileRequired = false,
addressLabel = (string) [
"IP1",
"IP2"
],
}
],
modelSupportInfo = (dr.san.ModelSupportInfo) [
(dr.san.ModelSupportInfo) {
dynamicType = <unset>,
product = "1818 FastT",
model = "DS5000 Series",
command = (dr.san.ModelSupportInfo.Command) [
"discoverArrays",
"discoverLuns",
"testFailover",
"failover"
],
},
(dr.san.ModelSupportInfo) {
dynamicType = <unset>,
product = "1815 FAStT",
model = "DS4800",
command = (dr.san.ModelSupportInfo.Command) [
"discoverArrays",
"discoverLuns",
"testFailover",
"failover"
],
},
(dr.san.ModelSupportInfo) {
dynamicType = <unset>,
product = "1814 200FAStT",
model = "DS4200",
command = (dr.san.ModelSupportInfo.Command) [
"discoverArrays",
"discoverLuns",
"testFailover",
"failover"
],
},
(dr.san.ModelSupportInfo) {
dynamicType = <unset>,
product = "1814 FAStT",
model = "DS4700",
command = (dr.san.ModelSupportInfo.Command) [
"discoverArrays",
"discoverLuns",
"testFailover",
"failover"
],
}
],
configDirectory = "C:/Program Files/VMware/VMware Site Recovery Manager/scripts/SAN/IBM",
}
~~2009-07-09 08:29:16.734 'SecondarySanProvider' 2100 verbose~~ Loading Storage Manager 'storage-manager-13' from DB object
~~2009-07-09 08:29:16.796 'SecondarySanProvider' 2100 verbose~~ Loading Array Manager 'array-manager-368' from DB object
~~2009-07-09 08:29:16.828 'SecondarySanProvider' 2100 verbose~~ Loading Array 'array-377' from DB object
~~2009-07-09 08:29:16.828 'SecondarySanProvider' 2100 verbose~~ Reconstructed Array 'array-377' from database
~~2009-07-09 08:29:16.828 'SecondarySanProvider' 2100 verbose~~ Scheduling synchronization timer for array '600a0b80002ab45c0000000049704cb3' to fire in 86400 seconds
~~2009-07-09 08:29:16.828 'SanConfigManager' 2100 trivia~~ Added storage port '0-20:04:00:A0:B8:2A:B4:5D' for array 'array-377'
~~2009-07-09 08:29:16.828 'SanConfigManager' 2100 trivia~~ Added storage port '0-20:04:00:A0:B8:2A:B4:5E' for array 'array-377'
~~2009-07-09 08:29:16.828 'SanConfigManager' 2100 trivia~~ Added storage port '0-20:05:00:A0:B8:2A:B4:5D' for array 'array-377'
~~2009-07-09 08:29:16.828 'SanConfigManager' 2100 trivia~~ Added storage port '0-20:05:00:A0:B8:2A:B4:5E' for array 'array-377'
~~2009-07-09 08:29:16.828 'SanConfigManager' 2100 trivia~~ Added 4 storage ports for array 'array-377'
~~2009-07-09 08:29:16.828 'SecondarySanProvider' 2100 verbose~~ Reconstructed Array Manager 'array-manager-368' from DB object
~~2009-07-09 08:29:16.828 'SecondarySanProvider' 2100 verbose~~ Storage Manager 'storage-manager-13' reconstructed from database
~~2009-07-09 08:29:16.828 'SecondarySanProvider' 2100 verbose~~ Secondary::SanProvider reconstructed from database
~~2009-07-09 08:29:16.828 'SecondarySanProvider' 2100 trivia~~ 'Load Secondary::SanProvider from DB object' took 0.093 seconds
~~2009-07-09 08:29:16.828 'SecondaryReplication' 2100 verbose~~ Loading ReplicationManager from DB object
~~2009-07-09 08:29:16.843 'Recovery' 2100 info~~ Populating Recovery Profile references...
~~2009-07-09 08:29:16.859 'Recovery' 2100 verbose~~ Resurrecting Recovery Profile from DB object: 'recovery-profile-533'
~~2009-07-09 08:29:16.937 'RSGroup-1414' 2100 verbose~~ Resurrecting RecoveryStepGroup 'RSGroup-1414'
~~2009-07-09 08:29:16.937 'RSGroup-1415' 2100 verbose~~ Resurrecting RecoveryStepGroup 'RSGroup-1415'
~~2009-07-09 08:29:16.937 'RSGroup-1416' 2100 verbose~~ Resurrecting RecoveryStepGroup 'RSGroup-1416'
~~2009-07-09 08:29:16.937 'RSGroup-1417' 2100 verbose~~ Resurrecting RecoveryStepGroup 'RSGroup-1417'
~~2009-07-09 08:29:16.953 'RSStorageOperationList-1418' 2100 verbose~~ Resurrecting RecoveryStepStorageOperationList 'RSStorageOperationList-1418'
~~2009-07-09 08:29:16.953 'RSGroup-1420' 2100 verbose~~ Resurrecting RecoveryStepGroup 'RSGroup-1420'
~~2009-07-09 08:29:16.953 'RSGroup-1421' 2100 verbose~~ Resurrecting RecoveryStepGroup 'RSGroup-1421'
~~2009-07-09 08:29:16.953 'RSGroup-1422' 2100 verbose~~ Resurrecting RecoveryStepGroup 'RSGroup-1422'
~~2009-07-09 08:29:16.953 'RSGroup-1423' 2100 verbose~~ Resurrecting RecoveryStepGroup 'RSGroup-1423'
~~2009-07-09 08:29:16.953 'RSGroup-1424' 2100 verbose~~ Resurrecting RecoveryStepGroup 'RSGroup-1424'
~~2009-07-09 08:29:16.968 'RSCalloutPrompt-1425' 2100 verbose~~ Resurrecting RecoveryStepCalloutPrompt 'RSCalloutPrompt-1425'
~~2009-07-09 08:29:16.968 'RSGroup-1426' 2100 verbose~~ Resurrecting RecoveryStepGroup 'RSGroup-1426'
~~2009-07-09 08:29:16.968 'RSGroup-1427' 2100 verbose~~ Resurrecting RecoveryStepGroup 'RSGroup-1427'
~~2009-07-09 08:29:16.968 'RSStorageOperationList-1428' 2100 verbose~~ Resurrecting RecoveryStepStorageOperationList 'RSStorageOperationList-1428'
~~2009-07-09 08:29:16.968 'Persistence' 2100 warning~~ Rolling back OPEN transaction context: txn_id=20
~~2009-07-09 08:29:16.968 'Recovery' 2100 info~~ RecoveryManagerImpl Loaded from DB
~~2009-07-09 08:29:17.000 'Locale' 2100 info~~ Locale subsystem initialized from ./locale/ with default locale en.
~~2009-07-09 08:29:17.921 'DrServiceInstance' 2100 info~~ Dr Service Instance is initialized.
~~2009-07-09 08:29:17.953 'authorize' 2100 error~~ Role referred to invalid privilege VcIntegrity.General.com.vmware.vcIntegrity.Configure, ignoring
~~2009-07-09 08:29:17.953 'authorize' 2100 error~~ Role referred to invalid privilege VcIntegrity.Updates.com.vmware.vcIntegrity.Remediate, ignoring
~~2009-07-09 08:29:17.968 'authorize' 2100 error~~ Role referred to invalid privilege VcIntegrity.Updates.com.vmware.vcIntegrity.Scan, ignoring
~~2009-07-09 08:29:17.968 'authorize' 2100 error~~ Role referred to invalid privilege VcIntegrity.Updates.com.vmware.vcIntegrity.ViewStatus, ignoring
~~2009-07-09 08:29:17.968 'authorize' 2100 error~~ Role referred to invalid privilege VcIntegrity.Baseline.com.vmware.vcIntegrity.AssignBaselines, ignoring
~~2009-07-09 08:29:17.968 'authorize' 2100 error~~ Role referred to invalid privilege VcIntegrity.Updates.com.vmware.vcIntegrity.ViewStatus, ignoring
~~2009-07-09 08:29:18.000 'authorize' 2100 warning~~ Ignoring unknown privilege 'VcIntegrity.General.com.vmware.vcIntegrity.Configure'
~~2009-07-09 08:29:18.000 'authorize' 2100 warning~~ Ignoring unknown privilege 'VcIntegrity.Updates.com.vmware.vcIntegrity.Remediate'
~~2009-07-09 08:29:18.000 'authorize' 2100 warning~~ Ignoring unknown privilege 'VcIntegrity.Updates.com.vmware.vcIntegrity.Scan'
~~2009-07-09 08:29:18.000 'authorize' 2100 warning~~ Ignoring unknown privilege 'VcIntegrity.Updates.com.vmware.vcIntegrity.ViewStatus'
~~2009-07-09 08:29:18.000 'authorize' 2100 warning~~ Ignoring unknown privilege 'VcIntegrity.Baseline.com.vmware.vcIntegrity.AssignBaselines'
~~2009-07-09 08:29:18.000 'authorize' 2100 warning~~ Ignoring unknown privilege 'VcIntegrity.Updates.com.vmware.vcIntegrity.ViewStatus'
~~2009-07-09 08:29:18.000 'PrimarySanProvider' 2100 info~~ SAN provider is ready
~~2009-07-09 08:29:18.000 'DrInventoryMapper: site-400' 2100 info~~ Registering initial IM callbacks for invMapper-site-400
~~2009-07-09 08:29:18.000 'Listener' 2100 info~~ Soap port: 8095
~~2009-07-09 08:29:18.015 'authorize' 3576 warning~~ Ignoring unknown privilege 'VcIntegrity.General.com.vmware.vcIntegrity.Configure'
~~2009-07-09 08:29:18.015 'authorize' 3576 warning~~ Ignoring unknown privilege 'VcIntegrity.Updates.com.vmware.vcIntegrity.Remediate'
~~2009-07-09 08:29:18.015 'authorize' 3576 warning~~ Ignoring unknown privilege 'VcIntegrity.Updates.com.vmware.vcIntegrity.Scan'
~~2009-07-09 08:29:18.015 'authorize' 3576 warning~~ Ignoring unknown privilege 'VcIntegrity.Updates.com.vmware.vcIntegrity.ViewStatus'
~~2009-07-09 08:29:18.015 'authorize' 3576 warning~~ Ignoring unknown privilege 'VcIntegrity.Baseline.com.vmware.vcIntegrity.AssignBaselines'
~~2009-07-09 08:29:18.015 'authorize' 3576 warning~~ Ignoring unknown privilege 'VcIntegrity.Updates.com.vmware.vcIntegrity.ViewStatus'
~~2009-07-09 08:29:18.015 'DrInventoryMapper: site-400' 3580 info~~ Syncing Objects
~~2009-07-09 08:29:18.046 'Listener' 2100 warning~~ Document root directory not found at ../vmodl
~~2009-07-09 08:29:18.046 'Listener' 2100 info~~ HTTP document root: C:\Program Files\VMware\VMware Site Recovery Manager\www
~~2009-07-09 08:29:18.046 'Listener' 2100 info~~ HTTP port: 8096
~~2009-07-09 08:29:18.046 'Listener' 2100 info~~ Added MIME: type=application/octet-stream, extension=exe
~~2009-07-09 08:29:18.046 'Listener' 2100 info~~ Dr listener initialized
~~2009-07-09 08:29:18.046 'App' 2100 info~~ Initializing SSL context
~~2009-07-09 08:29:18.046 'SoapAdapter' 2100 info~~ Http Service started: class Vmacore::Ssl::SSLServerSocketImpl:04DDDAD0
~~2009-07-09 08:29:18.046 'HttpSvc' 2100 info~~ Http Service started: TCPServerSocket(listen=:8096)
~~2009-07-09 08:29:18.046 'Listener' 2100 info~~ DR listener started
~~2009-07-09 08:29:18.046 'ExtApiListener' 2100 info~~ Soap port: 9007
~~2009-07-09 08:29:18.078 'ExtApiListener' 2100 error~~ Document root directory not found at ../vmodl
~~2009-07-09 08:29:18.078 'ExtApiListener' 2100 info~~ HTTP document root: C:\Program Files\VMware\VMware Site Recovery Manager\www
~~2009-07-09 08:29:18.078 'ExtApiListener' 2100 info~~ HTTP port: 9008
~~2009-07-09 08:29:18.078 'ExtApiListener' 2100 info~~ Dr external API listener initialized
~~2009-07-09 08:29:18.078 'ExtApiSoapAdapter' 2100 info~~ Http Service started: class Vmacore::Ssl::SSLServerSocketImpl:04D99050
~~2009-07-09 08:29:18.078 'HttpSvc' 2100 info~~ Http Service started: TCPServerSocket(listen=:9008)
~~2009-07-09 08:29:18.078 'ExtApiListener' 2100 info~~ DR external API listener started
~~2009-07-09 08:29:18.078 'App' 2100 info~~ serviceWin32,558 vmware-dr service started
~~2009-07-09 08:29:18.078 'App' 2100 info~~ serviceWin32,560 Log file location: C:\Documents and Settings\All Users\Application Data\VMware\VMware Site Recovery Manager\Logs
~~2009-07-09 08:30:16.484 'LocalSiteStatus' 3596 verbose~~ Free disk space: 129438 Mb
~~2009-07-09 08:30:16.484 'LocalSiteStatus' 3596 verbose~~ CPU usage: 3 %
~~2009-07-09 08:30:16.484 'LocalSiteStatus' 3596 verbose~~ Available memory: 3473 Mb
~~2009-07-09 08:30:16.531 'RemoteSite 'Protected Site'' 3596 info~~ Raising RemoteSitePingFailed event
~~2009-07-09 08:30:16.531 'RemoteSite 'Protected Site'' 3416 info~~ Attempting to reconnect
~~2009-07-09 08:30:16.531 'RemoteSite 'Protected Site'' 3416 info~~ Attempting to connect to remote site
~~2009-07-09 08:30:16.578 'LicenseManager' 3580 info~~ FlexLM: The feature 'SRM_PROTECTED_HOST' is not present on the license server or has expired.
~~2009-07-09 08:30:17.515 'RemoteSite 'Protected Site'' 3416 warning~~ Failed to connect to remote DR: Unexpected Vmacore::SystemException No connection could be made because the target machine actively refused it. (10061)
~~2009-07-09 08:31:16.484 'LocalSiteStatus' 3416 verbose~~ Free disk space: 129438 Mb
~~2009-07-09 08:31:16.484 'LocalSiteStatus' 3416 verbose~~ CPU usage: 1 %
~~2009-07-09 08:31:16.484 'LocalSiteStatus' 3416 verbose~~ Available memory: 3462 Mb
~~2009-07-09 08:31:16.531 'RemoteSite 'Protected Site'' 3416 warning~~ Failed to ping remote site
~~2009-07-09 08:31:17.515 'RemoteSite 'Protected Site'' 3580 info~~ Attempting to reconnect
~~2009-07-09 08:31:17.515 'RemoteSite 'Protected Site'' 3580 info~~ Attempting to connect to remote site
~~2009-07-09 08:31:18.593 'RemoteSite 'Protected Site'' 3580 warning~~ Failed to connect to remote DR: Unexpected Vmacore::SystemException No connection could be made because the target machine actively refused it. (10061)
~~2009-07-09 08:32:16.484 'LocalSiteStatus' 3596 verbose~~ Free disk space: 129438 Mb
~~2009-07-09 08:32:16.484 'LocalSiteStatus' 3596 verbose~~ CPU usage: 0 %
~~2009-07-09 08:32:16.484 'LocalSiteStatus' 3596 verbose~~ Available memory: 3461 Mb
~~2009-07-09 08:32:16.531 'RemoteSite 'Protected Site'' 3596 warning~~ Failed to ping remote site
~~2009-07-09 08:32:18.593 'RemoteSite 'Protected Site'' 3576 info~~ Attempting to reconnect
~~2009-07-09 08:32:18.593 'RemoteSite 'Protected Site'' 3576 info~~ Attempting to connect to remote site
~~2009-07-09 08:32:19.515 'RemoteSite 'Protected Site'' 3576 warning~~ Failed to connect to remote DR: Unexpected Vmacore::SystemException No connection could be made because the target machine actively refused it. (10061)
~~2009-07-09 08:33:16.484 'LocalSiteStatus' 3576 verbose~~ Free disk space: 129438 Mb
~~2009-07-09 08:33:16.484 'LocalSiteStatus' 3576 verbose~~ CPU usage: 0 %
~~2009-07-09 08:33:16.484 'LocalSiteStatus' 3576 verbose~~ Available memory: 3457 Mb
~~2009-07-09 08:33:16.531 'RemoteSite 'Protected Site'' 3576 info~~ Raising RemoteSiteDown event
~~2009-07-09 08:33:19.515 'RemoteSite 'Protected Site'' 3416 info~~ Attempting to reconnect
~~2009-07-09 08:33:19.515 'RemoteSite 'Protected Site'' 3416 info~~ Attempting to connect to remote site
~~2009-07-09 08:33:25.140 'RemoteSite 'Protected Site'' 3416 info~~ VC Connection: Logging in as user 'administrator'
~~2009-07-09 08:33:25.203 'RemoteSite 'Protected Site'' 3416 info~~ VC Connection: Logged in session 6343D5BF-3917-469F-ABBA-3ACDC4A290AB
~~2009-07-09 08:33:26.140 'RemoteSite 'Protected Site'' 3416 warning~~ Failed to connect to remote DR: Unexpected exception 'class Vmacore::Http::HttpException' HTTP error response: Service Unavailable
~~2009-07-09 08:33:26.140 'RemoteSite 'Protected Site'' 3416 verbose~~ VC Connection: Logging out session 6343D5BF-3917-469F-ABBA-3ACDC4A290AB
~~2009-07-09 08:33:26.203 'RemoteSite 'Protected Site'' 3416 verbose~~ VC Connection: Logged out session 6343D5BF-3917-469F-ABBA-3ACDC4A290AB
~~2009-07-09 08:34:16.484 'LocalSiteStatus' 3596 verbose~~ Free disk space: 129435 Mb
~~2009-07-09 08:34:16.484 'LocalSiteStatus' 3596 verbose~~ CPU usage: 3 %
~~2009-07-09 08:34:16.484 'LocalSiteStatus' 3596 verbose~~ Available memory: 3416 Mb
~~2009-07-09 08:34:16.531 'RemoteSite 'Protected Site'' 3596 warning~~ Failed to ping remote site
~~2009-07-09 08:34:16.578 'LicenseManager' 3596 verbose~~ FlexLM: Server Available.
~~2009-07-09 08:34:16.578 'LicenseManager' 3596 info~~ FlexLM: The feature 'SRM_PROTECTED_HOST' is not present on the license server or has expired.
~~2009-07-09 08:34:16.640 'HostLicenseMonitor' 3596 verbose~~ Checking Host Licenses
~~2009-07-09 08:34:16.640 'HostLicenseMonitor' 3596 verbose~~ No VMs to check.
~~2009-07-09 08:34:26.015 'MainVcConnection' 3596 info~~ VC Connection: Session: 3B967698-51CF-47D9-83ED-61C4E817F688, user Administrator, Active? true
~~2009-07-09 08:34:26.015 'SessionManager' 3596 verbose~~ LoginAdmin: Logging in DR session '56567FDF-4103-4E7F-8B5A-B799C256B6F8', user 'Administrator'
~~2009-07-09 08:34:26.015 'authorize' 3596 info~~ Auth: User Administrator
~~2009-07-09 08:34:26.015 'SessionManager' 3596 info~~ LoginAdmin: Logged in successfully
~~2009-07-09 08:34:26.140 'RemoteSite 'Protected Site'' 3580 info~~ Attempting to reconnect
~~2009-07-09 08:34:26.140 'RemoteSite 'Protected Site'' 3580 info~~ Attempting to connect to remote site
~~2009-07-09 08:34:26.156 'RemoteSite 'Protected Site'' 3580 info~~ VC Connection: Logging in as user 'administrator'
~~2009-07-09 08:34:26.171 'RemoteSite 'Protected Site'' 3580 info~~ VC Connection: Logged in session 271C8836-BA85-419C-B75E-4B413838AEFC
~~2009-07-09 08:34:26.203 'RemoteSite 'Protected Site'' 3580 info~~ DR Connection: Logging in admin
~~2009-07-09 08:34:26.203 'RemoteSite 'Protected Site'' 3580 info~~ DR Connection: Logged in admin session 81036575-6FE1-465D-ADB4-8CF4BD6BAD90
~~2009-07-09 08:34:26.203 'RemoteSite 'Protected Site'' 3580 info~~ Successfully connected to remote site
~~2009-07-09 08:34:26.203 'RemoteSite 'Protected Site'' 3580 info~~ Connection restored successfully
~~2009-07-09 08:34:26.218 'RemoteSite 'Protected Site'' 3580 verbose~~ Received new remote site health value: true
~~2009-07-09 08:34:26.312 'DrInventoryMapper: site-400' 3596 info~~ Syncing Objects
~~2009-07-09 08:35:16.484 'LocalSiteStatus' 3596 verbose~~ Free disk space: 129435 Mb
~~2009-07-09 08:35:16.484 'LocalSiteStatus' 3596 verbose~~ CPU usage: 1 %
~~2009-07-09 08:35:16.484 'LocalSiteStatus' 3596 verbose~~ Available memory: 3415 Mb
~~2009-07-09 08:36:16.484 'LocalSiteStatus' 3576 verbose~~ Free disk space: 129435 Mb
~~2009-07-09 08:36:16.484 'LocalSiteStatus' 3576 verbose~~ CPU usage: 0 %
~~2009-07-09 08:36:16.484 'LocalSiteStatus' 3576 verbose~~ Available memory: 3415 Mb
~~2009-07-09 08:37:16.484 'LocalSiteStatus' 3576 verbose~~ Free disk space: 129435 Mb
~~2009-07-09 08:37:16.484 'LocalSiteStatus' 3576 verbose~~ CPU usage: 4 %
~~2009-07-09 08:37:16.484 'LocalSiteStatus' 3576 verbose~~ Available memory: 3411 Mb
~~2009-07-09 08:38:16.484 'LocalSiteStatus' 3576 verbose~~ Free disk space: 129435 Mb
~~2009-07-09 08:38:16.484 'LocalSiteStatus' 3576 verbose~~ CPU usage: 1 %
~~2009-07-09 08:38:16.484 'LocalSiteStatus' 3576 verbose~~ Available memory: 3405 Mb
~~2009-07-09 08:39:16.484 'LocalSiteStatus' 3576 verbose~~ Free disk space: 129435 Mb
~~2009-07-09 08:39:16.484 'LocalSiteStatus' 3576 verbose~~ CPU usage: 8 %
~~2009-07-09 08:39:16.484 'LocalSiteStatus' 3576 verbose~~ Available memory: 3310 Mb
~~2009-07-09 08:39:16.578 'LicenseManager' 3576 verbose~~ FlexLM: Server Available.
~~2009-07-09 08:39:16.578 'LicenseManager' 3576 info~~ FlexLM: The feature 'SRM_PROTECTED_HOST' is not present on the license server or has expired.
~~2009-07-09 08:40:16.484 'LocalSiteStatus' 3416 verbose~~ Free disk space: 129435 Mb
~~2009-07-09 08:40:16.484 'LocalSiteStatus' 3416 verbose~~ CPU usage: 7 %
~~2009-07-09 08:40:16.484 'LocalSiteStatus' 3416 verbose~~ Available memory: 3269 Mb
~~2009-07-09 08:41:16.484 'LocalSiteStatus' 3580 verbose~~ Free disk space: 129435 Mb
~~2009-07-09 08:41:16.484 'LocalSiteStatus' 3580 verbose~~ CPU usage: 0 %
~~2009-07-09 08:41:16.484 'LocalSiteStatus' 3580 verbose~~ Available memory: 3270 Mb
~~2009-07-09 08:42:16.484 'LocalSiteStatus' 3580 verbose~~ Free disk space: 129435 Mb
~~2009-07-09 08:42:16.484 'LocalSiteStatus' 3580 verbose~~ CPU usage: 0 %
~~2009-07-09 08:42:16.484 'LocalSiteStatus' 3580 verbose~~ Available memory: 3269 Mb
~~2009-07-09 08:43:16.484 'LocalSiteStatus' 3580 verbose~~ Free disk space: 129434 Mb
~~2009-07-09 08:43:16.484 'LocalSiteStatus' 3580 verbose~~ CPU usage: 6 %
~~2009-07-09 08:43:16.484 'LocalSiteStatus' 3580 verbose~~ Available memory: 3252 Mb
~~2009-07-09 08:44:16.484 'LocalSiteStatus' 3580 verbose~~ Free disk space: 129434 Mb
~~2009-07-09 08:44:16.484 'LocalSiteStatus' 3580 verbose~~ CPU usage: 2 %
~~2009-07-09 08:44:16.484 'LocalSiteStatus' 3580 verbose~~ Available memory: 3249 Mb
~~2009-07-09 08:44:16.578 'LicenseManager' 3580 verbose~~ FlexLM: Server Available.
~~2009-07-09 08:44:16.578 'LicenseManager' 3580 info~~ FlexLM: The feature 'SRM_PROTECTED_HOST' is not present on the license server or has expired.
~~2009-07-09 08:44:34.234 'DrInventoryMapper: site-400' 3580 verbose~~ Local Object network-372 has been deleted. Removing from mapper
~~2009-07-09 08:44:34.234 'DrInventoryMapper: site-400' 3580 verbose~~ Removing 1 maps
~~2009-07-09 08:44:34.234 'DrInventoryMapper: site-400' 3580 verbose~~ No mapping found for 'vim.Network:network-372'
~~2009-07-09 08:44:34.281 'DrInventoryMapper: site-400' 3580 verbose~~ Local Object domain-c385 has been deleted. Removing from mapper
~~2009-07-09 08:44:34.281 'DrInventoryMapper: site-400' 3580 verbose~~ Local Object resgroup-387 has been deleted. Removing from mapper
~~2009-07-09 08:44:34.281 'DrInventoryMapper: site-400' 3580 verbose~~ Removing 1 maps
~~2009-07-09 08:44:34.281 'DrInventoryMapper: site-400' 3580 verbose~~ No mapping found for 'vim.ResourcePool:resgroup-387'
~~2009-07-09 08:45:16.484 'LocalSiteStatus' 3580 verbose~~ Free disk space: 129433 Mb
~~2009-07-09 08:45:16.484 'LocalSiteStatus' 3580 verbose~~ CPU usage: 2 %
~~2009-07-09 08:45:16.484 'LocalSiteStatus' 3580 verbose~~ Available memory: 3249 Mb
~~2009-07-09 08:46:16.484 'LocalSiteStatus' 3576 verbose~~ Free disk space: 129433 Mb
~~2009-07-09 08:46:16.484 'LocalSiteStatus' 3576 verbose~~ CPU usage: 2 %
~~2009-07-09 08:46:16.484 'LocalSiteStatus' 3576 verbose~~ Available memory: 3242 Mb
~~2009-07-09 08:47:02.640 'DrInventoryMapper: site-400' 3580 verbose~~ Local Object domain-s460 has been deleted. Removing from mapper
~~2009-07-09 08:47:02.640 'DrInventoryMapper: site-400' 3580 verbose~~ Local Object resgroup-462 has been deleted. Removing from mapper
~~2009-07-09 08:47:02.640 'DrInventoryMapper: site-400' 3580 verbose~~ Removing 1 maps
~~2009-07-09 08:47:02.640 'DrInventoryMapper: site-400' 3580 verbose~~ No mapping found for 'vim.ResourcePool:resgroup-462'
~~2009-07-09 08:47:06.343 'DrInventoryMapper: site-400' 3580 verbose~~ Local Object domain-s449 has been deleted. Removing from mapper
~~2009-07-09 08:47:06.343 'DrInventoryMapper: site-400' 3580 verbose~~ Local Object resgroup-451 has been deleted. Removing from mapper
~~2009-07-09 08:47:06.343 'DrInventoryMapper: site-400' 3580 verbose~~ Removing 1 maps
~~2009-07-09 08:47:06.343 'DrInventoryMapper: site-400' 3580 verbose~~ No mapping found for 'vim.ResourcePool:resgroup-451'
~~2009-07-09 08:47:16.484 'LocalSiteStatus' 3596 verbose~~ Free disk space: 129433 Mb
~~2009-07-09 08:47:16.484 'LocalSiteStatus' 3596 verbose~~ CPU usage: 3 %
~~2009-07-09 08:47:16.484 'LocalSiteStatus' 3596 verbose~~ Available memory: 3234 Mb
~~2009-07-09 08:47:24.750 'MainVcConnection' 3596 info~~ VC Connection: Session: A0AD4E02-B6D2-403A-898F-299588A015B9, user Administrator, Active? true
~~2009-07-09 08:47:24.750 'SessionManager' 3596 verbose~~ Logging in DR session '71FEDEBE-B4C7-475A-A8D9-623C2663E8EA', user 'Administrator', full name 'Administrator'
~~2009-07-09 08:47:24.750 'SessionManager' 3596 info~~ VC Connection: Logging in as user 'administrator'
~~2009-07-09 08:47:24.765 'SessionManager' 3596 info~~ VC Connection: Logged in session 74534205-DFAC-440D-A1AE-B07C9DEBE711
~~2009-07-09 08:47:24.765 'SessionManager' 3596 info~~ VC Connection: Impersonating user 'Administrator'
~~2009-07-09 08:47:24.765 'SessionManager' 3596 info~~ VC Connection: Impersonated user: 'Administrator'
~~2009-07-09 08:47:24.781 'SessionManager' 3596 info~~ Login: Logged in successfully
~~2009-07-09 08:47:36.562 'RemoteSite 'Protected Site'' 3580 info~~ VC Connection: Authenticating unprivileged user 'Administrator'
~~2009-07-09 08:47:36.578 'RemoteSite 'Protected Site'' 3580 info~~ VC Connection: Logged in session 089C093C-879D-4EAA-BB69-7F53C6F30399
~~2009-07-09 08:47:36.578 'RemoteSite 'Protected Site'' 3580 info~~ DR Connection: Logging in
~~2009-07-09 08:47:36.609 'RemoteSite 'Protected Site'' 3580 info~~ DR Connection: Logged in session DB50B86B-1CC7-48F0-A492-42999D38915C
~~2009-07-09 08:47:36.765 'MainVcConnection' 3596 info~~ VC Connection: Session: A0AD4E02-B6D2-403A-898F-299588A015B9, user Administrator, Active? true
~~2009-07-09 08:47:36.765 'SessionManager' 3596 verbose~~ Logging in DR session '0B539B29-ECBA-4894-83CA-3A6AE1EC9CE2', user 'Administrator', full name 'Administrator'
~~2009-07-09 08:47:36.765 'SessionManager' 3596 info~~ Login: Logged in successfully
~~2009-07-09 08:47:56.265 'DrSecondaryConfig' 3580 verbose~~ Temporary recovery profile 'session71FEDEBE-B4C7-475A-A8D9-623C2663E8EA1B007009-484B-4627-9300-7D80AE42ED3D' created
~~2009-07-09 08:48:11.656 'Recovery' 3596 verbose~~ Deleting profile test_failover
~~2009-07-09 08:48:16.484 'LocalSiteStatus' 3580 verbose~~ Free disk space: 129433 Mb
~~2009-07-09 08:48:16.484 'LocalSiteStatus' 3580 verbose~~ CPU usage: 7 %
~~2009-07-09 08:48:16.484 'LocalSiteStatus' 3580 verbose~~ Available memory: 3203 Mb
~~2009-07-09 08:48:48.734 'MainVcConnection' 3596 info~~ VC Connection: Session: 48ADF621-6961-4E8E-AFFD-7DE6AB1D5064, user Administrator, Active? true
~~2009-07-09 08:48:48.734 'SessionManager' 3596 verbose~~ Logging in DR session 'E1E2292F-76B9-48AF-9589-6C4BC972A182', user 'Administrator', full name 'Administrator'
~~2009-07-09 08:48:48.734 'SessionManager' 3596 info~~ VC Connection: Logging in as user 'administrator'
~~2009-07-09 08:48:48.765 'SessionManager' 3596 info~~ VC Connection: Logged in session E7840CCF-3324-4732-8BF3-1AF42D52BAA4
~~2009-07-09 08:48:48.765 'SessionManager' 3596 info~~ VC Connection: Impersonating user 'Administrator'
~~2009-07-09 08:48:48.765 'SessionManager' 3596 info~~ VC Connection: Impersonated user: 'Administrator'
~~2009-07-09 08:48:48.765 'SessionManager' 3596 info~~ Login: Logged in successfully
~~2009-07-09 08:48:48.812 'MainVcConnection' 3596 info~~ VC Connection: Session: 0CA3E46D-5DB6-4D40-952A-4641AA91CA66, user Administrator, Active? true
~~2009-07-09 08:48:48.812 'SessionManager' 3596 verbose~~ Logging in DR session 'DD8F2198-4057-4CE8-B7F5-14F1C1305748', user 'Administrator', full name 'Administrator'
~~2009-07-09 08:48:48.828 'SessionManager' 3596 info~~ VC Connection: Logging in as user 'administrator'
~~2009-07-09 08:48:48.843 'SessionManager' 3596 info~~ VC Connection: Logged in session D51A8759-31CD-4C66-B0E7-AD1A1A7C58B0
~~2009-07-09 08:48:48.843 'SessionManager' 3596 info~~ VC Connection: Impersonating user 'Administrator'
~~2009-07-09 08:48:48.843 'SessionManager' 3596 info~~ VC Connection: Impersonated user: 'Administrator'
~~2009-07-09 08:48:48.843 'SessionManager' 3596 info~~ Login: Logged in successfully
~~2009-07-09 08:48:48.937 'RemoteSite 'Protected Site'' 3576 info~~ VC Connection: Logging in as user 'administrator'
~~2009-07-09 08:48:49.062 'RemoteSite 'Protected Site'' 3576 info~~ VC Connection: Logged in session F4B27A7C-530F-4635-B71C-45D404B055DF
~~2009-07-09 08:48:49.062 'RemoteSite 'Protected Site'' 3576 info~~ VC Connection: Impersonating user 'Administrator'
~~2009-07-09 08:48:49.156 'RemoteSite 'Protected Site'' 3576 info~~ VC Connection: Impersonated user: 'Administrator'
~~2009-07-09 08:48:49.265 'RemoteSite 'Protected Site'' 3576 info~~ DR Connection: Logging in
~~2009-07-09 08:48:49.375 'RemoteSite 'Protected Site'' 3576 info~~ DR Connection: Logged in session 33B3A014-026C-4B02-A521-40FCBE60EA0D
~~2009-07-09 08:49:16.484 'LocalSiteStatus' 3416 verbose~~ Free disk space: 129433 Mb
~~2009-07-09 08:49:16.484 'LocalSiteStatus' 3416 verbose~~ CPU usage: 1 %
~~2009-07-09 08:49:16.484 'LocalSiteStatus' 3416 verbose~~ Available memory: 3203 Mb
~~2009-07-09 08:49:16.578 'LicenseManager' 3416 verbose~~ FlexLM: Server Available.
~~2009-07-09 08:49:16.578 'LicenseManager' 3416 info~~ FlexLM: The feature 'SRM_PROTECTED_HOST' is not present on the license server or has expired.
~~2009-07-09 08:50:03.718 'SecondaryReplication' 3576 verbose~~ Saving ReplicationManager to DB object
~~2009-07-09 08:50:03.734 'SecondaryReplication' 3576 verbose~~ Saving ShadowProtectionProfile to DB object
~~2009-07-09 08:50:03.796 'SecondaryReplication' 3576 info~~ Created shadow protection profile 'srm_test_group'
~~2009-07-09 08:50:03.921 'RemoteDrSitePM Protected Site' 3580 warning~~ No object changes were reported:
(vmodl.query.PropertyCollector.ObjectUpdate) {
dynamicType = <unset>,
kind = "enter",
obj = 'dr.primary.ContinuousProtectionProfile:continuous-profile-2340',
}
~~2009-07-09 08:50:04.218 'SecondaryReplication' 3576 info~~ Creating new shadow group in shadow profile 'dr.secondary.ShadowProtectionProfile:shadow-profile-1880'
~~2009-07-09 08:50:04.218 'SecondaryReplication' 3576 verbose~~ Requesting provider's permission to create shadow group
~~2009-07-09 08:50:04.328 'SecondaryReplication' 3576 verbose~~ Saving ShadowProtectionProfile to DB object
~~2009-07-09 08:50:04.343 'SecondaryReplication' 3576 verbose~~ Saving ShadowGroup to DB object
~~2009-07-09 08:50:04.390 'SecondaryReplication' 3576 info~~ Created shadow group 'srm_test_group'
~~2009-07-09 08:50:04.859 'SecondarySanProvider' 3576 trivia~~ Persisting SecondarySanProvider to database
~~2009-07-09 08:50:04.859 'SecondarySanProvider' 3576 verbose~~ Saving Secondary::SanProvider to DB object
~~2009-07-09 08:50:04.859 'SecondarySanProvider' 3576 verbose~~ Saved Secondary::SanProvider to DB object
~~2009-07-09 08:50:04.859 'SecondarySanProvider' 3576 trivia~~ 'Save Secondary::SanProvider to DB object' took 0 seconds
~~2009-07-09 08:50:04.937 'SecondarySanProvider' 3576 info~~ Added shadow group 'shadow-group-1885':
(dr.secondary.SanShadowGroupDetails) {
1 dynamicType = <unset>,
1 arrayKey = "600a0b80002ab45c0000000049704cb3",
1 replicatedDatastore = (dr.secondary.SanShadowGroupDetails.ReplicatedDatastore) [
1 (dr.secondary.SanShadowGroupDetails.ReplicatedDatastore) {
1 dynamicType = <unset>,
1 primaryUrl = "sanfs://vmfs_uuid:4a54ae4d-26e165e9-1688-001a6466d5da/",
1 peerInfo = (dr.san.Lun.PeerInfo) [
1 (dr.san.Lun.PeerInfo) {
1 dynamicType = <unset>,
1 arrayKey = "600a0b80002ab45c0000000049704cb3",
1 lunKey = "600a0b80002ab45c00000a8f4a3f9620",
1 }
1] ,
1 }
1] ,
1 lunGroup = 'dr.san.LunGroup:lun-group-1833',
1 }
~~2009-07-09 08:50:04.937 'SecondaryReplication' 3576 verbose~~ Saving ShadowGroup to DB object
~~2009-07-09 08:50:05.015 'SecondarySanProvider' 3580 trivia~~ Received update for dr.san.LunGroup:lun-group-1833:
(vmodl.query.PropertyCollector.Change) [
(vmodl.query.PropertyCollector.Change) {
dynamicType = <unset>,
name = "settings.replicatedDatastore",
op = "assign",
val = (dr.san.LunGroup.ReplicatedDatastore) [
(dr.san.LunGroup.ReplicatedDatastore) {
dynamicType = <unset>,
datastore = 'vim.Datastore:datastore-483',
lun = (dr.san.Lun) [
(dr.san.Lun) {
dynamicType = <unset>,
info = (dr.san.Lun.Info) {
dynamicType = <unset>,
arrayId = "600a0b80002ab4b00000000049704bef",
id = "600a0b80002ab4b0000009c94a5494bf",
wwn = <unset>,
number = (dr.san.Lun.Number) [
(dr.san.Lun.Number) {
dynamicType = <unset>,
value = 6,
initiatorGroupId = "85000000600a0b80002ab45a0036090e4a51abc9",
targetId = <unset>,
}
],
consistencyGroupId = <unset>,
},
peerInfo = (dr.san.Lun.PeerInfo) {
dynamicType = <unset>,
arrayKey = "600a0b80002ab45c0000000049704cb3",
lunKey = "600a0b80002ab45c00000a8f4a3f9620",
},
}
],
fullyReplicated = true,
}
],
},
(vmodl.query.PropertyCollector.Change) {
dynamicType = <unset>,
name = "settings.replicatedRdmDevice",
op = "assign",
val = (dr.san.LunGroup.ReplicatedRdmDevice) [],
}
]
~~2009-07-09 08:50:05.062 'SecondarySanProvider' 3580 trivia~~ Persisting SecondarySanProvider to database
~~2009-07-09 08:50:05.062 'SecondarySanProvider' 3580 verbose~~ Saving Secondary::SanProvider to DB object
~~2009-07-09 08:50:05.062 'SecondarySanProvider' 3580 verbose~~ Saved Secondary::SanProvider to DB object
~~2009-07-09 08:50:05.062 'SecondarySanProvider' 3580 trivia~~ 'Save Secondary::SanProvider to DB object' took 0 seconds
~~2009-07-09 08:50:05.093 'SecondarySanProvider' 3580 info~~ Updated shadow group 'shadow-group-1885' details: (dr.secondary.SanShadowGroupDetails) {
dynamicType = <unset>,
arrayKey = "600a0b80002ab45c0000000049704cb3",
replicatedDatastore = (dr.secondary.SanShadowGroupDetails.ReplicatedDatastore) [
(dr.secondary.SanShadowGroupDetails.ReplicatedDatastore) {
dynamicType = <unset>,
primaryUrl = "sanfs://vmfs_uuid:4a54ae4d-26e165e9-1688-001a6466d5da/",
peerInfo = (dr.san.Lun.PeerInfo) [
(dr.san.Lun.PeerInfo) {
dynamicType = <unset>,
arrayKey = "600a0b80002ab45c0000000049704cb3",
lunKey = "600a0b80002ab45c00000a8f4a3f9620",
}
],
}
],
lunGroup = 'dr.san.LunGroup:lun-group-1833',
}
~~2009-07-09 08:50:05.234 'SecondaryReplication' 3576 info~~ Adding shadow VMs to shadow group 'dr.secondary.ShadowGroup:shadow-group-1885'
~~2009-07-09 08:50:05.234 'SecondaryReplication' 3576 verbose~~ vmSpecList:
(dr.secondary.ShadowVmSpecInternal) [
1 (dr.secondary.ShadowVmSpecInternal) {
1 dynamicType = <unset>,
1 shadowVmSpec = (dr.secondary.ShadowVmSpec) {
1 dynamicType = <unset>,
1 name = "SRM_VM",
1 folder = 'vim.Folder:group-v116',
1 resourcePool = 'vim.ResourcePool:resgroup-472',
1 hostSystem = 'vim.HostSystem:host-452',
1 fileInfo = (dr.vimext.FileInfo) {
1 dynamicType = <unset>,
1 datastore = (dr.vimext.SanProviderDatastoreLocator) {
1 dynamicType = <unset>,
1 primaryUrl = "sanfs://vmfs_uuid:4a54ae4d-26e165e9-1688-001a6466d5da/",
1 },
1 vmFilePath = "SRM_VM/SRM_VM.vmx",
1 snapshotDirectory = (dr.vimext.DirectoryLocator) {
1 dynamicType = <unset>,
1 datastore = (dr.vimext.SanProviderDatastoreLocator) {
1 dynamicType = <unset>,
1 primaryUrl = "sanfs://vmfs_uuid:4a54ae4d-26e165e9-1688-001a6466d5da/",
1 },
1 path = "SRM_VM",
1 },
1 suspendDirectory = (dr.vimext.DirectoryLocator) null,
1 logDirectory = (dr.vimext.DirectoryLocator) null,
1 },
1 scratchDatastore = (dr.vimext.ExistingDatastoreLocator) {
1 dynamicType = <unset>,
1 datastore = 'vim.Datastore:datastore-457',
1 },
1 devices = (dr.vimext.DeviceInfo) [
1 (dr.vimext.DeviceInfo) {
1 dynamicType = <unset>,
1 device = (vim.vm.device.VirtualPCNet32) {
1 dynamicType = <unset>,
1 key = 4000,
1 deviceInfo = (vim.Description) {
1 dynamicType = <unset>,
1 label = "Network Adapter 1",
1 summary = "VM Network",
1 },
1 backing = (vim.vm.device.VirtualEthernetCard.NetworkBackingInfo) {
1 dynamicType = <unset>,
1 deviceName = "VM Network",
1 useAutoDetect = false,
1 network = 'vim.Network:network-54',
1 },
1 connectable = (vim.vm.device.VirtualDevice.ConnectInfo) {
1 dynamicType = <unset>,
1 startConnected = true,
1 allowGuestControl = true,
1 connected = true,
1 },
1 controllerKey = 100,
1 unitNumber = 7,
1 addressType = "assigned",
1 macAddress = "00:50:56:83:13:18",
1 wakeOnLanEnabled = true,
1 },
1 backing = (dr.vimext.NetworkDeviceBackingLocator) {
1 dynamicType = <unset>,
1 network = 'vim.Network:network-459',
1 },
1 },
1 (dr.vimext.DeviceInfo) {
1 dynamicType = <unset>,
1 device = (vim.vm.device.VirtualDisk) {
1 dynamicType = <unset>,
1 key = 2000,
1 deviceInfo = (vim.Description) {
1 dynamicType = <unset>,
1 label = "Hard Disk 1",
1 summary = "20,971,520 KB",
1 },
1 backing = (vim.vm.device.VirtualDisk.FlatVer2BackingInfo) {
1 dynamicType = <unset>,
1 fileName = "SRM_store SRM_VM/SRM_VM.vmdk",
1 datastore = 'vim.Datastore:datastore-483',
1 diskMode = "persistent",
1 split = false,
1 writeThrough = false,
1 thinProvisioned = false,
1 uuid = "6000C29b-1423-32ed-9cc5-3f6c3f5b9ac0",
1 },
1 connectable = (vim.vm.device.VirtualDevice.ConnectInfo) null,
1 controllerKey = 1000,
1 unitNumber = 0,
1 capacityInKB = 20971520,
1 shares = (vim.SharesInfo) {
1 dynamicType = <unset>,
1 shares = 1000,
1 level = "normal",
1 },
1 },
1 backing = (dr.vimext.DiskBackingLocator) {
1 dynamicType = <unset>,
1 diskChain = (dr.vimext.DiskBackingLocator.DiskChain) {
1 dynamicType = <unset>,
1 head = (dr.vimext.VmFileLocator) {
1 dynamicType = <unset>,
1 directory = (dr.vimext.DirectoryLocator) {
1 dynamicType = <unset>,
1 datastore = (dr.vimext.SanProviderDatastoreLocator) {
1 dynamicType = <unset>,
1 primaryUrl = "sanfs://vmfs_uuid:4a54ae4d-26e165e9-1688-001a6466d5da/",
1 },
1 path = "SRM_VM",
1 },
1 fileName = "SRM_VM.vmdk",
1 },
1 parentChain = (dr.vimext.DiskBackingLocator.DiskChain) null,
1 },
1 },
1 }
1] ,
1 snapshotLayout = (dr.vimext.VmSnapshotLayout) null,
1 recoverySettings = (dr.secondary.ShadowRecoverySettings) {
1 dynamicType = <unset>,
1 changeVersion = <unset>,
1 recoveryPriority = 50,
1 customizationSpecName = <unset>,
1 },
1 },
1 protectedVm = 'dr.primary.ProtectedVm:protected-vm-2370',
1 vm = 'vim.VirtualMachine:vm-485',
1 }
1]
~~2009-07-09 08:50:05.234 'com.vmware.vcDr.ShadowGroup.AddVmTask-Task' 3576 verbose~~ Task created
~~2009-07-09 08:50:05.234 'SimpleTaskManager' 3576 verbose~~ Adding task com.vmware.vcDr.ShadowGroup.AddVmTask-0
~~2009-07-09 08:50:05.234 'com.vmware.vcDr.ShadowGroup.AddVmTask-Task' 3576 info~~ State set to running
~~2009-07-09 08:50:05.234 'com.vmware.vcDr.ShadowGroup.AddVmTask-Task' 3576 verbose~~ Scheduling work item
~~2009-07-09 08:50:05.234 'com.vmware.vcDr.ShadowGroup.AddVmTask-Task' 3580 info~~ Running work method
~~2009-07-09 08:50:05.234 'com.vmware.vcDr.ShadowGroup.AddVmTask-Task' 3580 info~~ Work function yielded
~~2009-07-09 08:50:05.421 'SecondaryReplication' 3580 verbose~~ Found 2 hosts compatible with datastore 'datastore-457' and resource pool 'resgroup-472'
~~2009-07-09 08:50:05.734 'com.vmware.vcDr.ShadowGroup.AddVmTask-Task' 3596 verbose~~ Progress advanced to 90
~~2009-07-09 08:50:05.734 'SecondaryReplication' 3596 verbose~~ Creation of VM failed with error (vim.fault.CannotAccessFile) {
1 dynamicType = <unset>,
1 file = "SRM_store",
1 msg = "Unable to access file.
1 SRM_store"
1 }
~~2009-07-09 08:50:05.734 'com.vmware.vcDr.ShadowGroup.AddVmTask-Task' 3596 verbose~~ Error set to (dr.secondary.fault.RemoteCreateVmFault) {
1 dynamicType = <unset>,
1 remoteFault = (vim.fault.CannotAccessFile) {
1 dynamicType = <unset>,
1 file = "SRM_store",
1 msg = "Unable to access file.
1 SRM_store"
1 },
1 msg = ""
1 }
~~2009-07-09 08:50:05.734 'com.vmware.vcDr.ShadowGroup.AddVmTask-Task' 3596 info~~ State set to error
~~2009-07-09 08:50:05.734 'SecondaryReplication' 3580 verbose~~ Saving ShadowGroup to DB object
~~2009-07-09 08:50:05.765 'SecondaryReplication' 3580 verbose~~ Empty shadow VM list on which to disable unwanted methods
~~2009-07-09 08:50:16.484 'LocalSiteStatus' 3596 verbose~~ Free disk space: 129433 Mb
~~2009-07-09 08:50:16.484 'LocalSiteStatus' 3596 verbose~~ CPU usage: 0 %
~~2009-07-09 08:50:16.484 'LocalSiteStatus' 3596 verbose~~ Available memory: 3202 Mb
~~2009-07-09 08:51:05.234 'SimpleTaskManager' 3488 verbose~~ Scanning for tasks to reap
~~2009-07-09 08:51:05.234 'SimpleTaskManager' 3488 verbose~~ Task com.vmware.vcDr.ShadowGroup.AddVmTask-0 marked as complete
~~2009-07-09 08:51:16.484 'LocalSiteStatus' 3488 verbose~~ Free disk space: 129433 Mb
~~2009-07-09 08:51:16.484 'LocalSiteStatus' 3488 verbose~~ CPU usage: 1 %
~~2009-07-09 08:51:16.484 'LocalSiteStatus' 3488 verbose~~ Available memory: 3202 Mb
~~2009-07-09 08:52:05.234 'com.vmware.vcDr.ShadowGroup.AddVmTask-Task' 3580 verbose~~ Task destroyed
~~2009-07-09 08:52:05.234 'SimpleTaskManager' 3580 verbose~~ Scanning for tasks to reap
~~2009-07-09 08:52:16.484 'LocalSiteStatus' 3416 verbose~~ Free disk space: 129434 Mb
~~2009-07-09 08:52:16.484 'LocalSiteStatus' 3416 verbose~~ CPU usage: 2 %
~~2009-07-09 08:52:16.484 'LocalSiteStatus' 3416 verbose~~ Available memory: 3199 Mb
~~2009-07-09 08:53:16.484 'LocalSiteStatus' 3596 verbose~~ Free disk space: 129434 Mb
~~2009-07-09 08:53:16.484 'LocalSiteStatus' 3596 verbose~~ CPU usage: 1 %
~~2009-07-09 08:53:16.484 'LocalSiteStatus' 3596 verbose~~ Available memory: 3199 Mb
~~2009-07-09 08:54:16.484 'LocalSiteStatus' 3576 verbose~~ Free disk space: 129434 Mb
~~2009-07-09 08:54:16.484 'LocalSiteStatus' 3576 verbose~~ CPU usage: 3 %
~~2009-07-09 08:54:16.484 'LocalSiteStatus' 3576 verbose~~ Available memory: 3197 Mb
~~2009-07-09 08:54:16.578 'LicenseManager' 3576 verbose~~ FlexLM: Server Available.
~~2009-07-09 08:54:16.578 'LicenseManager' 3576 info~~ FlexLM: The feature 'SRM_PROTECTED_HOST' is not present on the license server or has expired.
~~2009-07-09 08:55:16.484 'LocalSiteStatus' 2984 verbose~~ Free disk space: 129433 Mb
~~2009-07-09 08:55:16.484 'LocalSiteStatus' 2984 verbose~~ CPU usage: 4 %
~~2009-07-09 08:55:16.484 'LocalSiteStatus' 2984 verbose~~ Available memory: 3197 Mb
~~2009-07-09 08:56:16.484 'LocalSiteStatus' 3416 verbose~~ Free disk space: 129433 Mb
~~2009-07-09 08:56:16.484 'LocalSiteStatus' 3416 verbose~~ CPU usage: 5 %
~~2009-07-09 08:56:16.484 'LocalSiteStatus' 3416 verbose~~ Available memory: 3193 Mb
~~2009-07-09 08:56:48.968 'SecondaryReplication' 3576 verbose~~ Saving ShadowGroup to DB object
~~2009-07-09 08:56:49.031 'SecondaryReplication' 3576 info~~ Removing shadow group 'dr.secondary.ShadowGroup:shadow-group-1885' from profile 'dr.secondary.ShadowProtectionProfile:shadow-profile-1880'
~~2009-07-09 08:56:49.031 'SecondaryReplication' 3576 verbose~~ Informing provider of shadow group removal
~~2009-07-09 08:56:49.031 'SecondarySanProvider' 3576 trivia~~ Persisting SecondarySanProvider to database
~~2009-07-09 08:56:49.031 'SecondarySanProvider' 3576 verbose~~ Saving Secondary::SanProvider to DB object
~~2009-07-09 08:56:49.031 'SecondarySanProvider' 3576 verbose~~ Saved Secondary::SanProvider to DB object
~~2009-07-09 08:56:49.031 'SecondarySanProvider' 3576 trivia~~ 'Save Secondary::SanProvider to DB object' took 0 seconds
~~2009-07-09 08:56:49.031 'SecondarySanProvider' 3576 info~~ Removed shadow group 'shadow-group-1885'
~~2009-07-09 08:56:49.031 'Recovery' 3576 info~~ ShadowUpdateCallback
~~2009-07-09 08:56:49.031 'SecondaryReplication' 3576 verbose~~ Saving ShadowProtectionProfile to DB object
~~2009-07-09 08:56:49.046 'SecondaryReplication' 3576 info~~ Removed shadow group 'srm_test_group'
~~2009-07-09 08:56:49.046 'PropertyCollector' 2984 warning~~ GetPropertyProvider failed for shadow-group-1885
~~2009-07-09 08:56:49.046 'PropertyCollector' 3416 warning~~ GetPropertyProvider failed for shadow-group-1885
~~2009-07-09 08:56:49.125 'SecondaryReplication' 3576 verbose~~ Saving ReplicationManager to DB object
~~2009-07-09 08:56:49.140 'RemoteDrSitePM Protected Site' 3488 info~~ Object being watched was destroyed: group-2348 fault:
(vmodl.fault.ManagedObjectNotFound) {
dynamicType = <unset>,
obj = 'dr.primary.ReplicationGroup:group-2348',
msg = ""
}
~~2009-07-09 08:56:49.140 'SecondaryReplication' 3576 info~~ Removed shadow protection profile 'srm_test_group'
~~2009-07-09 08:56:49.234 'RemoteDrSitePM Protected Site' 3488 info~~ Object being watched was destroyed: continuous-profile-2340 fault:
(vmodl.fault.ManagedObjectNotFound) {
dynamicType = <unset>,
obj = 'dr.primary.ContinuousProtectionProfile:continuous-profile-2340',
msg = ""
}
~~2009-07-09 08:57:16.484 'LocalSiteStatus' 3488 verbose~~ Free disk space: 129433 Mb
~~2009-07-09 08:57:16.484 'LocalSiteStatus' 3488 verbose~~ CPU usage: 1 %
~~2009-07-09 08:57:16.484 'LocalSiteStatus' 3488 verbose~~ Available memory: 3191 Mb
~~2009-07-09 08:57:20.375 'SecondaryReplication' 3576 verbose~~ Saving ReplicationManager to DB object
~~2009-07-09 08:57:20.375 'SecondaryReplication' 3576 verbose~~ Saving ShadowProtectionProfile to DB object
~~2009-07-09 08:57:20.406 'SecondaryReplication' 3576 info~~ Created shadow protection profile 'srm_test_group'
~~2009-07-09 08:57:20.453 'RemoteDrSitePM Protected Site' 3488 warning~~ No object changes were reported:
(vmodl.query.PropertyCollector.ObjectUpdate) {
dynamicType = <unset>,
kind = "enter",
obj = 'dr.primary.ContinuousProtectionProfile:continuous-profile-2380',
}
~~2009-07-09 08:57:20.765 'SecondaryReplication' 3576 info~~ Creating new shadow group in shadow profile 'dr.secondary.ShadowProtectionProfile:shadow-profile-1905'
~~2009-07-09 08:57:20.765 'SecondaryReplication' 3576 verbose~~ Requesting provider's permission to create shadow group
~~2009-07-09 08:57:20.781 'SecondaryReplication' 3576 verbose~~ Saving ShadowProtectionProfile to DB object
~~2009-07-09 08:57:20.781 'SecondaryReplication' 3576 verbose~~ Saving ShadowGroup to DB object
~~2009-07-09 08:57:20.812 'SecondaryReplication' 3576 info~~ Created shadow group 'srm_test_group'
~~2009-07-09 08:57:21.265 'SecondarySanProvider' 3576 trivia~~ Persisting SecondarySanProvider to database
~~2009-07-09 08:57:21.265 'SecondarySanProvider' 3576 verbose~~ Saving Secondary::SanProvider to DB object
~~2009-07-09 08:57:21.265 'SecondarySanProvider' 3576 verbose~~ Saved Secondary::SanProvider to DB object
~~2009-07-09 08:57:21.265 'SecondarySanProvider' 3576 trivia~~ 'Save Secondary::SanProvider to DB object' took 0 seconds
~~2009-07-09 08:57:21.281 'SecondarySanProvider' 3576 info~~ Added shadow group 'shadow-group-1910':
(dr.secondary.SanShadowGroupDetails) {
1 dynamicType = <unset>,
1 arrayKey = "600a0b80002ab45c0000000049704cb3",
1 replicatedDatastore = (dr.secondary.SanShadowGroupDetails.ReplicatedDatastore) [
1 (dr.secondary.SanShadowGroupDetails.ReplicatedDatastore) {
1 dynamicType = <unset>,
1 primaryUrl = "sanfs://vmfs_uuid:4a54ae4d-26e165e9-1688-001a6466d5da/",
1 peerInfo = (dr.san.Lun.PeerInfo) [
1 (dr.san.Lun.PeerInfo) {
1 dynamicType = <unset>,
1 arrayKey = "600a0b80002ab45c0000000049704cb3",
1 lunKey = "600a0b80002ab45c00000a8f4a3f9620",
1 }
1] ,
1 }
1] ,
1 lunGroup = 'dr.san.LunGroup:lun-group-1833',
1 }
~~2009-07-09 08:57:21.281 'SecondaryReplication' 3576 verbose~~ Saving ShadowGroup to DB object
~~2009-07-09 08:57:21.453 'SecondaryReplication' 3576 info~~ Adding shadow VMs to shadow group 'dr.secondary.ShadowGroup:shadow-group-1910'
~~2009-07-09 08:57:21.453 'SecondaryReplication' 3576 verbose~~ vmSpecList:
(dr.secondary.ShadowVmSpecInternal) [
1 (dr.secondary.ShadowVmSpecInternal) {
1 dynamicType = <unset>,
1 shadowVmSpec = (dr.secondary.ShadowVmSpec) {
1 dynamicType = <unset>,
1 name = "SRM_VM",
1 folder = 'vim.Folder:group-v116',
1 resourcePool = 'vim.ResourcePool:resgroup-472',
1 hostSystem = 'vim.HostSystem:host-452',
1 fileInfo = (dr.vimext.FileInfo) {
1 dynamicType = <unset>,
1 datastore = (dr.vimext.SanProviderDatastoreLocator) {
1 dynamicType = <unset>,
1 primaryUrl = "sanfs://vmfs_uuid:4a54ae4d-26e165e9-1688-001a6466d5da/",
1 },
1 vmFilePath = "SRM_VM/SRM_VM.vmx",
1 snapshotDirectory = (dr.vimext.DirectoryLocator) {
1 dynamicType = <unset>,
1 datastore = (dr.vimext.SanProviderDatastoreLocator) {
1 dynamicType = <unset>,
1 primaryUrl = "sanfs://vmfs_uuid:4a54ae4d-26e165e9-1688-001a6466d5da/",
1 },
1 path = "SRM_VM",
1 },
1 suspendDirectory = (dr.vimext.DirectoryLocator) null,
1 logDirectory = (dr.vimext.DirectoryLocator) null,
1 },
1 scratchDatastore = (dr.vimext.ExistingDatastoreLocator) {
1 dynamicType = <unset>,
1 datastore = 'vim.Datastore:datastore-477',
1 },
1 devices = (dr.vimext.DeviceInfo) [
1 (dr.vimext.DeviceInfo) {
1 dynamicType = <unset>,
1 device = (vim.vm.device.VirtualPCNet32) {
1 dynamicType = <unset>,
1 key = 4000,
1 deviceInfo = (vim.Description) {
1 dynamicType = <unset>,
1 label = "Network Adapter 1",
1 summary = "VM Network",
1 },
1 backing = (vim.vm.device.VirtualEthernetCard.NetworkBackingInfo) {
1 dynamicType = <unset>,
1 deviceName = "VM Network",
1 useAutoDetect = false,
1 network = 'vim.Network:network-54',
1 },
1 connectable = (vim.vm.device.VirtualDevice.ConnectInfo) {
1 dynamicType = <unset>,
1 startConnected = true,
1 allowGuestControl = true,
1 connected = true,
1 },
1 controllerKey = 100,
1 unitNumber = 7,
1 addressType = "assigned",
1 macAddress = "00:50:56:83:13:18",
1 wakeOnLanEnabled = true,
1 },
1 backing = (dr.vimext.NetworkDeviceBackingLocator) {
1 dynamicType = <unset>,
1 network = 'vim.Network:network-459',
1 },
1 },
1 (dr.vimext.DeviceInfo) {
1 dynamicType = <unset>,
1 device = (vim.vm.device.VirtualDisk) {
1 dynamicType = <unset>,
1 key = 2000,
1 deviceInfo = (vim.Description) {
1 dynamicType = <unset>,
1 label = "Hard Disk 1",
1 summary = "20,971,520 KB",
1 },
1 backing = (vim.vm.device.VirtualDisk.FlatVer2BackingInfo) {
1 dynamicType = <unset>,
1 fileName = "SRM_store SRM_VM/SRM_VM.vmdk",
1 datastore = 'vim.Datastore:datastore-483',
1 diskMode = "persistent",
1 split = false,
1 writeThrough = false,
1 thinProvisioned = false,
1 uuid = "6000C29b-1423-32ed-9cc5-3f6c3f5b9ac0",
1 },
1 connectable = (vim.vm.device.VirtualDevice.ConnectInfo) null,
1 controllerKey = 1000,
1 unitNumber = 0,
1 capacityInKB = 20971520,
1 shares = (vim.SharesInfo) {
1 dynamicType = <unset>,
1 shares = 1000,
1 level = "normal",
1 },
1 },
1 backing = (dr.vimext.DiskBackingLocator) {
1 dynamicType = <unset>,
1 diskChain = (dr.vimext.DiskBackingLocator.DiskChain) {
1 dynamicType = <unset>,
1 head = (dr.vimext.VmFileLocator) {
1 dynamicType = <unset>,
1 directory = (dr.vimext.DirectoryLocator) {
1 dynamicType = <unset>,
1 datastore = (dr.vimext.SanProviderDatastoreLocator) {
1 dynamicType = <unset>,
1 primaryUrl = "sanfs://vmfs_uuid:4a54ae4d-26e165e9-1688-001a6466d5da/",
1 },
1 path = "SRM_VM",
1 },
1 fileName = "SRM_VM.vmdk",
1 },
1 parentChain = (dr.vimext.DiskBackingLocator.DiskChain) null,
1 },
1 },
1 }
1] ,
1 snapshotLayout = (dr.vimext.VmSnapshotLayout) null,
1 recoverySettings = (dr.secondary.ShadowRecoverySettings) {
1 dynamicType = <unset>,
1 changeVersion = <unset>,
1 recoveryPriority = 50,
1 customizationSpecName = <unset>,
1 },
1 },
1 protectedVm = 'dr.primary.ProtectedVm:protected-vm-2410',
1 vm = 'vim.VirtualMachine:vm-485',
1 }
1]
~~2009-07-09 08:57:21.453 'com.vmware.vcDr.ShadowGroup.AddVmTask-Task' 3576 verbose~~ Task created
~~2009-07-09 08:57:21.453 'SimpleTaskManager' 3576 verbose~~ Adding task com.vmware.vcDr.ShadowGroup.AddVmTask-2
~~2009-07-09 08:57:21.453 'com.vmware.vcDr.ShadowGroup.AddVmTask-Task' 3576 info~~ State set to running
~~2009-07-09 08:57:21.453 'com.vmware.vcDr.ShadowGroup.AddVmTask-Task' 3576 verbose~~ Scheduling work item
~~2009-07-09 08:57:21.453 'com.vmware.vcDr.ShadowGroup.AddVmTask-Task' 3488 info~~ Running work method
~~2009-07-09 08:57:21.453 'com.vmware.vcDr.ShadowGroup.AddVmTask-Task' 3488 info~~ Work function yielded
~~2009-07-09 08:57:21.484 'SecondarySanProvider' 3576 trivia~~ Received update for dr.san.LunGroup:lun-group-1833:
(vmodl.query.PropertyCollector.Change) [
(vmodl.query.PropertyCollector.Change) {
dynamicType = <unset>,
name = "settings.replicatedDatastore",
op = "assign",
val = (dr.san.LunGroup.ReplicatedDatastore) [
(dr.san.LunGroup.ReplicatedDatastore) {
dynamicType = <unset>,
datastore = 'vim.Datastore:datastore-483',
lun = (dr.san.Lun) [
(dr.san.Lun) {
dynamicType = <unset>,
info = (dr.san.Lun.Info) {
dynamicType = <unset>,
arrayId = "600a0b80002ab4b00000000049704bef",
id = "600a0b80002ab4b0000009c94a5494bf",
wwn = <unset>,
number = (dr.san.Lun.Number) [
(dr.san.Lun.Number) {
dynamicType = <unset>,
value = 6,
initiatorGroupId = "85000000600a0b80002ab45a0036090e4a51abc9",
targetId = <unset>,
}
],
consistencyGroupId = <unset>,
},
peerInfo = (dr.san.Lun.PeerInfo) {
dynamicType = <unset>,
arrayKey = "600a0b80002ab45c0000000049704cb3",
lunKey = "600a0b80002ab45c00000a8f4a3f9620",
},
}
],
fullyReplicated = true,
}
],
},
(vmodl.query.PropertyCollector.Change) {
dynamicType = <unset>,
name = "settings.replicatedRdmDevice",
op = "assign",
val = (dr.san.LunGroup.ReplicatedRdmDevice) [],
}
]
~~2009-07-09 08:57:21.609 'SecondaryReplication' 3488 verbose~~ Found 2 hosts compatible with datastore 'datastore-477' and resource pool 'resgroup-472'
~~2009-07-09 08:58:16.484 'LocalSiteStatus' 3580 verbose~~ Free disk space: 129433 Mb
~~2009-07-09 08:58:16.484 'LocalSiteStatus' 3580 verbose~~ CPU usage: 1 %
~~2009-07-09 08:58:16.484 'LocalSiteStatus' 3580 verbose~~ Available memory: 3189 Mb
~~2009-07-09 08:58:21.453 'SimpleTaskManager' 3596 verbose~~ Scanning for tasks to reap
~~2009-07-09 08:59:12.109 'com.vmware.vcDr.ShadowGroup.AddVmTask-Task' 2984 verbose~~ Progress advanced to 90
~~2009-07-09 08:59:12.109 'SecondaryReplication' 2984 verbose~~ Creation of VM ''vim.VirtualMachine:vm-479'' complete
~~2009-07-09 08:59:12.218 'SecondaryReplication' 3488 verbose~~ Saving ShadowGroup to DB object
~~2009-07-09 08:59:12.234 'SecondaryReplication' 3488 verbose~~ Saving ShadowVm to DB object
~~2009-07-09 08:59:12.421 'com.vmware.vcDr.ShadowGroup.AddVmTask-Task' 3488 verbose~~ Result set to 'dr.secondary.ShadowVm:shadow-vm-1920'
~~2009-07-09 08:59:12.421 'com.vmware.vcDr.ShadowGroup.AddVmTask-Task' 3488 info~~ State set to success
~~2009-07-09 08:59:12.718 'SecondarySanProvider' 3576 trivia~~ Persisting SecondarySanProvider to database
~~2009-07-09 08:59:12.718 'SecondarySanProvider' 3576 verbose~~ Saving Secondary::SanProvider to DB object
~~2009-07-09 08:59:12.734 'SecondarySanProvider' 3576 verbose~~ Saved Secondary::SanProvider to DB object
~~2009-07-09 08:59:12.734 'SecondarySanProvider' 3576 trivia~~ 'Save Secondary::SanProvider to DB object' took 0.015 seconds
~~2009-07-09 08:59:12.765 'SecondarySanProvider' 3576 info~~ Updated shadow group 'shadow-group-1910' details: (dr.secondary.SanShadowGroupDetails) {
dynamicType = <unset>,
arrayKey = "600a0b80002ab45c0000000049704cb3",
replicatedDatastore = (dr.secondary.SanShadowGroupDetails.ReplicatedDatastore) [
(dr.secondary.SanShadowGroupDetails.ReplicatedDatastore) {
dynamicType = <unset>,
primaryUrl = "sanfs://vmfs_uuid:4a54ae4d-26e165e9-1688-001a6466d5da/",
peerInfo = (dr.san.Lun.PeerInfo) [
(dr.san.Lun.PeerInfo) {
dynamicType = <unset>,
arrayKey = "600a0b80002ab45c0000000049704cb3",
lunKey = "600a0b80002ab45c00000a8f4a3f9620",
}
],
}
],
lunGroup = 'dr.san.LunGroup:lun-group-1833',
}
~~2009-07-09 08:59:12.828 'MakeVmsValidTask-Task' 3580 verbose~~ Task created
~~2009-07-09 08:59:12.828 'SimpleTaskManager' 3580 verbose~~ Adding task MakeVmsValidTask-4
~~2009-07-09 08:59:12.828 'MakeVmsValidTask-Task' 3580 info~~ State set to running
~~2009-07-09 08:59:12.828 'MakeVmsValidTask-Task' 3580 verbose~~ Scheduling work item
~~2009-07-09 08:59:12.828 'MakeVmsValidTask-Task' 3576 info~~ Running work method
~~2009-07-09 08:59:12.828 'SecondarySanProvider' 3576 trivia~~ Devices for shadow vm 'shadow-vm-1920':
~~2009-07-09 08:59:12.828 'SecondarySanProvider' 3576 trivia~~
(dr.vimext.DeviceInfo) {
1 dynamicType = <unset>,
1 device = (vim.vm.device.VirtualDisk) {
1 dynamicType = <unset>,
1 key = 2000,
1 deviceInfo = (vim.Description) {
1 dynamicType = <unset>,
1 label = "Hard Disk 1",
1 summary = "20,971,520 KB",
1 },
1 backing = (vim.vm.device.VirtualDisk.FlatVer2BackingInfo) {
1 dynamicType = <unset>,
1 fileName = "SRM_store SRM_VM/SRM_VM.vmdk",
1 datastore = 'vim.Datastore:datastore-483',
1 diskMode = "persistent",
1 split = false,
1 writeThrough = false,
1 thinProvisioned = false,
1 uuid = "6000C29b-1423-32ed-9cc5-3f6c3f5b9ac0",
1 },
1 connectable = (vim.vm.device.VirtualDevice.ConnectInfo) null,
1 controllerKey = 1000,
1 unitNumber = 0,
1 capacityInKB = 20971520,
1 shares = (vim.SharesInfo) {
1 dynamicType = <unset>,
1 shares = 1000,
1 level = "normal",
1 },
1 },
1 backing = (dr.vimext.DiskBackingLocator) {
1 dynamicType = <unset>,
1 diskChain = (dr.vimext.DiskBackingLocator.DiskChain) {
1 dynamicType = <unset>,
1 head = (dr.vimext.VmFileLocator) {
1 dynamicType = <unset>,
1 directory = (dr.vimext.DirectoryLocator) {
1 dynamicType = <unset>,
1 datastore = (dr.vimext.SanProviderDatastoreLocator) {
1 dynamicType = <unset>,
1 primaryUrl = "sanfs://vmfs_uuid:4a54ae4d-26e165e9-1688-001a6466d5da/",
1 },
1 path = "SRM_VM",
1 },
1 fileName = "SRM_VM.vmdk",
1 },
1 parentChain = (dr.vimext.DiskBackingLocator.DiskChain) null,
1 },
1 },
1 }
~~2009-07-09 08:59:12.828 'SecondarySanProvider' 3576 trivia~~
(dr.vimext.DeviceInfo) {
1 dynamicType = <unset>,
1 device = (vim.vm.device.VirtualPCNet32) {
1 dynamicType = <unset>,
1 key = 4000,
1 deviceInfo = (vim.Description) {
1 dynamicType = <unset>,
1 label = "Network Adapter 1",
1 summary = "VM Network",
1 },
1 backing = (vim.vm.device.VirtualEthernetCard.NetworkBackingInfo) {
1 dynamicType = <unset>,
1 deviceName = "VM Network",
1 useAutoDetect = false,
1 network = 'vim.Network:network-54',
1 },
1 connectable = (vim.vm.device.VirtualDevice.ConnectInfo) {
1 dynamicType = <unset>,
1 startConnected = true,
1 allowGuestControl = true,
1 connected = true,
1 },
1 controllerKey = 100,
1 unitNumber = 7,
1 addressType = "assigned",
1 macAddress = "00:50:56:83:13:18",
1 wakeOnLanEnabled = true,
1 },
1 backing = (dr.vimext.NetworkDeviceBackingLocator) {
1 dynamicType = <unset>,
1 network = 'vim.Network:network-459',
1 },
1 }
~~2009-07-09 08:59:12.828 'SecondarySanProvider' 3576 info~~ Accepted 1 new vms to shadow group MoId 'shadow-group-1910'
~~2009-07-09 08:59:12.828 'Recovery' 3576 info~~ ShadowUpdateCallback
~~2009-07-09 08:59:12.828 'SecondaryReplication' 3576 verbose~~ Marking shadow VM 'dr.secondary.ShadowVm:shadow-vm-1920' valid
~~2009-07-09 08:59:12.828 'SecondaryReplication' 3576 verbose~~ Saving ShadowVm to DB object
~~2009-07-09 08:59:12.828 'MainVcPM' 3580 warning~~ No object changes were reported:
(vmodl.query.PropertyCollector.ObjectUpdate) {
dynamicType = <unset>,
kind = "enter",
obj = 'vim.VirtualMachine:vm-479',
}
~~2009-07-09 08:59:12.953 'MakeVmsValidTask-Task' 3576 verbose] Result set to (dr.secondary.ShadowGroup.ShadowVmFaultPair) [~~
~~2009-07-09 08:59:12.953 'MakeVmsValidTask-Task' 3576 info~~ State set to success
~~2009-07-09 08:59:12.953 'MakeVmsValidTask-Task' 3576 info~~ Work function completed successfully
~~2009-07-09 08:59:16.484 'LocalSiteStatus' 2984 verbose~~ Free disk space: 129432 Mb
~~2009-07-09 08:59:16.484 'LocalSiteStatus' 2984 verbose~~ CPU usage: 1 %
~~2009-07-09 08:59:16.484 'LocalSiteStatus' 2984 verbose~~ Available memory: 3188 Mb
~~2009-07-09 08:59:16.578 'LicenseManager' 2984 verbose~~ FlexLM: Server Available.
~~2009-07-09 08:59:16.578 'LicenseManager' 2984 info~~ FlexLM: The feature 'SRM_PROTECTED_HOST' is not present on the license server or has expired.
~~2009-07-09 08:59:21.453 'SimpleTaskManager' 3576 verbose~~ Scanning for tasks to reap
~~2009-07-09 08:59:21.453 'SimpleTaskManager' 3576 verbose~~ Task com.vmware.vcDr.ShadowGroup.AddVmTask-2 marked as complete
~~2009-07-09 08:59:21.453 'SimpleTaskManager' 3576 verbose~~ Task MakeVmsValidTask-4 marked as complete
~~2009-07-09 09:00:16.484 'LocalSiteStatus' 3576 verbose~~ Free disk space: 129432 Mb
~~2009-07-09 09:00:16.484 'LocalSiteStatus' 3576 verbose~~ CPU usage: 0 %
~~2009-07-09 09:00:16.484 'LocalSiteStatus' 3576 verbose~~ Available memory: 3188 Mb
~~2009-07-09 09:00:21.453 'com.vmware.vcDr.ShadowGroup.AddVmTask-Task' 2108 verbose~~ Task destroyed
~~2009-07-09 09:00:21.453 'MakeVmsValidTask-Task' 2108 verbose~~ Task destroyed
~~2009-07-09 09:00:21.453 'SimpleTaskManager' 2108 verbose~~ Scanning for tasks to reap
~~2009-07-09 09:01:16.484 'LocalSiteStatus' 3596 verbose~~ Free disk space: 129433 Mb
~~2009-07-09 09:01:16.484 'LocalSiteStatus' 3596 verbose~~ CPU usage: 1 %
~~2009-07-09 09:01:16.484 'LocalSiteStatus' 3596 verbose~~ Available memory: 3312 Mb
~~2009-07-09 09:02:16.484 'LocalSiteStatus' 3576 verbose~~ Free disk space: 129433 Mb
~~2009-07-09 09:02:16.484 'LocalSiteStatus' 3576 verbose~~ CPU usage: 0 %
~~2009-07-09 09:02:16.484 'LocalSiteStatus' 3576 verbose~~ Available memory: 3311 Mb
~~2009-07-09 09:03:16.484 'LocalSiteStatus' 2984 verbose~~ Free disk space: 129433 Mb
~~2009-07-09 09:03:16.484 'LocalSiteStatus' 2984 verbose~~ CPU usage: 0 %
~~2009-07-09 09:03:16.484 'LocalSiteStatus' 2984 verbose~~ Available memory: 3309 Mb
~~2009-07-09 09:04:16.484 'LocalSiteStatus' 3576 verbose~~ Free disk space: 129433 Mb
~~2009-07-09 09:04:16.484 'LocalSiteStatus' 3576 verbose~~ CPU usage: 0 %
~~2009-07-09 09:04:16.484 'LocalSiteStatus' 3576 verbose~~ Available memory: 3304 Mb
~~2009-07-09 09:04:16.578 'LicenseManager' 3576 verbose~~ FlexLM: Server Available.
~~2009-07-09 09:04:16.578 'LicenseManager' 3576 info~~ FlexLM: The feature 'SRM_PROTECTED_HOST' is not present on the license server or has expired.

Re: DS4000 SRM issues

mariab — Wed, 08 Jul 2009 20:30:41 GMT

I believe this log is from the protected site. Could you post log from recovery site?

Re: DS4000 SRM issues

FG0711 — Wed, 08 Jul 2009 20:17:12 GMT

logifile attached

Re: DS4000 SRM issues

mariab — Wed, 08 Jul 2009 20:06:38 GMT

If you still get the error, could you post SRM log from recovery site?

Re: DS4000 SRM issues

FG0711 — Wed, 08 Jul 2009 20:05:39 GMT

thanks for your feedback. i just refreshed the "storage" in config tab for both hosts i have and the datastore is there

Re: DS4000 SRM issues

mariab — Wed, 08 Jul 2009 19:58:18 GMT

This error usually means that temporary datastore for placeholder VMs is not visible to all hosts in recovery cluster.

Re: DS4000 SRM issues

FG0711 — Wed, 08 Jul 2009 19:54:17 GMT

i got the failover (-test and real) working and enabled HA and DRS in both sites. right after that i got the following error when trying to create a protection group: "Virtual machine could not be created on recovery site: Resource pool, datastore and host specified for shadow virtual machine are not compatible with each other"

I disable HA and DRS but still keep getting the same error. i don't think anything else changed from yesterday.

any feeback is greatly appreciated.

Re: DS4000 SRM issues

FG0711 — Tue, 07 Jul 2009 20:24:19 GMT

dex_1234, thanks for your help again

Re: DS4000 SRM issues

dex_1234 — Tue, 07 Jul 2009 19:58:39 GMT

Here's more info on the SRM patch:

http://kb.vmware.com/selfservice/microsites/search.do?language=en_US&cmd=displayKC&externalId=1010053

Re: DS4000 SRM issues

dex_1234 — Tue, 07 Jul 2009 19:52:11 GMT

I almost forgot to mention, there is a cummulative patch out for SRM released in back in April to fix various issues, it may address the OS heartbeat timeout issue. I didn't see the heartbeat issue when I ran through my config with the patch installed. I've attached it. (Install on SRM servers)

Testfailover cleanup should be automated, but as for failover, it's a bit manual. I've went ahead and attached the failover and failback tutorials as well.

Re: DS4000 SRM issues

FG0711 — Tue, 07 Jul 2009 19:06:38 GMT

this was super helpfull. yes i noticed that on a second go-around my testfailover run ok. i will modify the files the way you suggeseted. it did timed out on "wait for OS heartbeat". now i need to clean everything out by hand. is there a way to start from a step in the script ?

Re: DS4000 SRM issues

dex_1234 — Tue, 07 Jul 2009 18:25:47 GMT

I'm assumming you're running a "testfailover" of your recovery plan, during this process SRM will initiated flascopies of the secondary logical drives(via the SRA) to be presented to your ESX host(s). SRM will also invoke ESX to rescan for new LUNs. I've noticed that sometimes it doesn't alway pick up new luns on the first rescan and if you were to go and issue a manual hba rescan(recovery side) and run the test failover again it would succeed successfully. Not something desirable in a real situation, but there is a way to tell ESX to scan twice automatically. To force ESX to rescan twice automatically, modify the vmware-dr.xml in "*C:\program files\Site Recovery Manager\Config*" on your SRM server at both sites (restart SRM)

Just a note on a testfailover, SRM will not touch the replication that has been configured on the storage system. That's why the flashcopies are used. During an actual failover, the secondary logical drives are promoted to primary and presented to the ESX host directly, no flashcopies involved. I've also attached a quick tutorial on what's suppose to happen during a testfailover, it was some stuff I put togethether a while back for some in-house training.(based on DS4000 storage) Hopefully it helps to clear some things up. One more thing, detach the CD-ROM from the VMs that you're trying to failover if any are configured. SRM doesn't like attached CD-ROMs.

Re: DS4000 SRM issues

FG0711 — Tue, 07 Jul 2009 18:10:31 GMT

cj_1223,

I am still working on actually making it work. What helped to fix the issue was dex_1234 pointing out that LUNs have to be mapped to a hostgroup and not to a default group. I remapped all LUNS to the hostgroup and REMOVED the mapping from default. I also changed the "access" LUN mapping in the default group to a different number from the "access" LUN in the hostgroup ( had them both mapped to 2). Not sure if that was the issue.

After that I had to stop replication in order for SRM to find the replicated datastore. After that with the relication on everything looked OK.

Re: DS4000 SRM issues

FG0711 — Tue, 07 Jul 2009 16:45:15 GMT

i am now testing a recovery plan and it fails in step 2 - prepare storage ( attach disks ......). Will SRM stop replication and change recovery LUNs to Read/Write ? or should i stop replication before running the failover plan ?

Thanks

Re: DS4000 SRM issues

cj1223 — Tue, 07 Jul 2009 16:37:12 GMT

just curious. I have been following this forum intently as we are experiencing a similiar issue.

Can you post how you got it all working?

Much appreciated.

Re: DS4000 SRM issues

FG0711 — Tue, 07 Jul 2009 16:16:04 GMT

issue resolved. thank you for help

Re: DS4000 SRM issues

dex_1234 — Tue, 07 Jul 2009 15:48:56 GMT

Let me know if you detect your luns on the recovery side, if you can't get things working post your vmware-dr log and storage subsystem profile log( under the "storagesubsystem->profile" in StorageManager) for the recovery side

Re: DS4000 SRM issues

FG0711 — Tue, 07 Jul 2009 13:48:08 GMT

I just re-did all LUN mappings. SRM can now see the LUN in the Protected site, but does not see it in the recovery site.

Re: DS4000 SRM issues

FG0711 — Tue, 07 Jul 2009 13:21:19 GMT

attachment

Re: DS4000 SRM issues

FG0711 — Tue, 07 Jul 2009 13:19:01 GMT

Dex_1234,

Attahed are some screenshots of the storage. Which log files should I get from DS4700 ? Thank you

Re: DS4000 SRM issues

dex_1234 — Mon, 06 Jul 2009 20:14:58 GMT

As you've stated earlier the line: "LunMapping.mapRef is NULL" is troubling.

1 192.168.100.31192.168.100.32"C:/Program Files/VMware/VMware Site Recovery Manager/scripts/SAN/IBM/SMsra.exe" discoverLuns arrayName=DS4800 arrayAddress=192.168.100.31 arrayAddress=192.168.100.32 arrayPassword= arrayId=600a0b80002ab4b00000000049704bef logLevel=trivia outputFile=cliDLun33962009-07-06:: 15:07:43:INFO:MAIN:Entry
1 ArrayId=600a0b80002ab4b00000000049704bef
1 bindToController succesfull
1 Current CGN=2361
1 No. of Arrays found=1
1 ArrayId in Cmd =600a0b80002ab4b00000000049704bef
1 ArrayId in List=600a0b80002ab4b00000000049704bef
1 Cluster Len=1
1 Host Len=2
1 Got a Cluster
1 Cluster Ref=…
1 Cluster Ref=85000000600a0b80002ab45a0036090e4a51abc9
1 Pushing in an Initiator
1 InitiatorID=2100001b32042bdf
1 Pushing in an Initiator
1 InitiatorID=2100001b3204f9df
1 Pushing in an Initiator
1 InitiatorID=2100001b320454e0
1 Pushing in an Initiator
1 InitiatorID=2100001b32042cdf
1 Added host Ref=84000000600a0b80002ab45a003007404a3cc1d9
1 ObjBundle Host Ref=84000000600a0b80002ab45a003007404a3cc1d9
1 hostInResponse=1
1 Added host Ref=84000000600a0b80002ab45a003007404a3cc1d9
1 ObjBundle Host Ref=84000000600a0b80002ab45a003007434a3cc21a
1 Added host Ref=84000000600a0b80002ab45a003007434a3cc21a
1 ObjBundle Host Ref=84000000600a0b80002ab45a003007434a3cc21a
1 hostInResponse=1
1 Got a Mirrored LUN
#1 LunMapping.mapRef is NULL
1 peerArrayId=600a0b80002ab45c0000000049704cb3
1 Result has=23
1 2009-07-06:: 15:07:44:INFO:main:Done with discoverLuns

The SRA connects to the controllers and can pull the host/hostgroup info just fine. It detects that a mirrorred lun exist, but
we get the "LunMapping.mapref is NULL" error. What you should see is something similar to the following after the "Got a Mirrored LUN" line:(example is from my setup)

Got a Mirrored LUN
(2009-04-27 10:21:02) ~~.\cli\sraStorageArrayCommandExecutor.cpp:429~~::VERBOSE::SMsra::StorageArrayCommandExecutor::getClusterRef::Got a Host's clusterRef
InitiatorGroupID=85000000600a0b8000293ade003659ae49e3246e
peerArrayId=600a0b80001133e800000000481eb21a

I know you already have a support ticket in and this looks to be an issue between the SRA and storage system, so it'll have to go down the IBM side. The example of
my log above was based on SRA build 01.00.35.12. One thing you might want to try while you work through the support process is back down to the previous SRA build(01.00.35.12)
and give it another attempt to see if we get the same "LunMapping.mapref is NULL" error. This is the build before the current SRA build that's out there for download(01.01.35.01). In parallel I can continue to help you out and look into things, would it be possible
to get a copy of your storage subsystem profiles for both sites?

Re: DS4000 SRM issues

FG0711 — Mon, 06 Jul 2009 19:18:29 GMT

dex_1234:

re-installed sras on both sides. restarted srm services on both sites, still the same problem. see attached

thanks

Re: DS4000 SRM issues

dex_1234 — Mon, 06 Jul 2009 15:08:53 GMT

Completely uninstall the SRA and then re-install it.(both sides) After that, restart SRM(I'd do it for both protected and recovery sides) and run through the array manager configuration again. Post your vmware-dr log after this run. dex

Re: DS4000 SRM issues

FG0711 — Mon, 06 Jul 2009 14:37:18 GMT

Just noticed something:

It looks like SRA thinks that my storage is DS4800. It's DS4700-70 could that be a problem ??? Also, the 4th line from the bottom says "NULL" - is that a problem ?

I appreciate any feedback.

Thank you

+++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++

Manager/scripts/SAN/IBM/discoverLuns.pl" temp956
1 2009-07-06:: 10:06:43:QUITE:main:Logging data for discover luns
1 2009-07-06:: 10:06:43:INFO:parseDiscoverLunInput:Parsing the lun discovery input.....
1 192.168.100.31192.168.100.32"C:/Program Files/VMware/VMware Site Recovery Manager/scripts/SAN/IBM/SMsra.exe" discoverLuns arrayName=DS4800 arrayAddress=192.168.100.31 arrayAddress=192.168.100.32 arrayPassword= arrayId=600a0b80002ab4b00000000049704bef logLevel=trivia outputFile=cliDLun12082009-07-06:: 10:06:43:INFO:MAIN:Entry
1 ArrayId=600a0b80002ab4b00000000049704bef
1 bindToController succesfull
1 Current CGN=2336
1 No. of Arrays found=1
1 ArrayId in Cmd =600a0b80002ab4b00000000049704bef
1 ArrayId in List=600a0b80002ab4b00000000049704bef
1 Cluster Len=1
1 Host Len=2
1 Got a Cluster
1 Cluster Ref=...
1 Cluster Ref=85000000600a0b80002ab45a0036090e4a51abc9
1 Pushing in an Initiator
1 InitiatorID=2100001b32042bdf
1 Pushing in an Initiator
1 InitiatorID=2100001b3204f9df
1 Pushing in an Initiator
1 InitiatorID=2100001b320454e0
1 Pushing in an Initiator
1 InitiatorID=2100001b32042cdf
1 Added host Ref=84000000600a0b80002ab45a003007404a3cc1d9
1 ObjBundle Host Ref=84000000600a0b80002ab45a003007404a3cc1d9
1 hostInResponse=1
1 Added host Ref=84000000600a0b80002ab45a003007404a3cc1d9
1 ObjBundle Host Ref=84000000600a0b80002ab45a003007434a3cc21a
1 Added host Ref=84000000600a0b80002ab45a003007434a3cc21a
1 ObjBundle Host Ref=84000000600a0b80002ab45a003007434a3cc21a
1 hostInResponse=1
1 Got a Mirrored LUN
1 LunMapping.mapRef is NULL
1 peerArrayId=600a0b80002ab45c0000000049704cb3
1 Result has=23
1 2009-07-06:: 10:06:44:INFO:main:Done with discoverLuns

Re: DS4000 SRM issues

FG0711 — Mon, 06 Jul 2009 13:49:54 GMT

Dex_1234,

I recreated the hostgroups and confirmed all IP addresses of DS4700 controllers. Still no good. I may try to uninstll and re-install everything. Thanks

attached are screenshots (storage manager and SRM)

Re: DS4000 SRM issues

FG0711 — Sat, 04 Jul 2009 01:53:48 GMT

Dex_1234

Thank you very much for your post. I did make a mistake in entering the IP address (missed one "0"). I do have my hosts (ESX1-1, ESX1-2 on one side and ESX2-1, ESX2-2 on the DR site) mapped to the default group as well as all LUNs. I had a hostgroup "Hosts" in each site, but got rid off it and mapped everything to "default" when SRM did not find the LUNs at first. I will recreate the hostgroups and fix IP problem on Monday. I hope it'll work. Thanks again for your help

Re: DS4000 SRM issues

dex_1234 — Thu, 02 Jul 2009 21:08:39 GMT

I took a look at your vmware-dr log and have a few questions:

1. The DiscoverLun request has your controller IPs as 192.168.10.31 and 192.168.100.32 is this correct?

2. Looks like you have two "hosts" configured on the storage system, are the luns you're trying detect currently mapped to the "default group"? If they
are mapped to the default group the IBM SRA does not detect luns mapped to the default group. You have to map your luns
to a host or hostgroup with members.(hostgroups with no members are not supported)

Re: DS4000 SRM issues

FG0711 — Thu, 02 Jul 2009 17:30:17 GMT

I switched to a single fabric - both ESX hosts and ports 1 of both controllers are in the same zone on the same vsan. I also created a new LUN #6 - SRM_TEST with one VM and its datastore on it, 60GB. Setup replication to the protected side's storage ( same name). Enable flash copy on both sites. >>> Still can not see the LUNS, protected or recovery. I also opened the support cases with IBM and Vmware. We had a couple of webex sessions, but no resolution so far

The log file do not indicate any errors. (attached)

Any ideas? Thank you

Re: DS4000 SRM issues

dex_1234 — Sat, 27 Jun 2009 04:31:12 GMT

The current SRA algorithm will look in the current array group that the logical drive is in to put the repository, if not enough space is available it'll scan the entire subsytem and place the repository in the first available free capacity it finds. In your case, the repository will be place in the RAID5 array. (note: flashcopies are only taken of the secondary logical drive in a mirror pair at the "recovery" site during an SRM test failover)

SRM will work with both the DS4700 model 70 or 72. With the model 70, as you mentioned when ERM is enabled you'll lose a host port on each controller for mirroring, leaving you with only one port on each controller for host communication. It's recommended that you design the fabric to enable each HBA initiator port to see both controllers in your subsystem. In order to do this with the model 70 you will have to use a single fibre switch or redundant switches with an ISL. This will provide your ESX server(s) with redundant paths to your storage system(4 path). The reason why this is recommended is to avoid logical drive failover in the event of a single path failure. The storage system is designed to perform logical drive failover, but it's something you want to avoid if possible. If a logical drive failover does occur, the storage subsystem has to change it's ownership, synchronize cache, re-route IOs through the alternate controller and if the logical drive is part of a mirror, all of the backend end mirroring operations has to change controller ownership as well. If the primary logical drive in a mirror pair changes controller ownership, so does the secondary logical drive. The recommended SAN design is an attempt to minimize the need for this. Yes, the system is designed to be fault tolerant, but it's something you really want to try and avoid.

Re: DS4000 SRM issues

FG0711 — Sat, 27 Jun 2009 02:05:48 GMT

TheGallowMan ,

Thanks for feedback. Which version of DS4700 did you use -70 or -72? If you used -70, how was the FC fabric configured? We have port #2 of both controllers in the protected site and recovery site used for Enh. Remote Mirroring so it leaves only one port per controller for Host connectivity. I do use May 09 version of IBM ds4000/5000 SRA. I have 500GB of unconfigured free space, however this space is within a configured RAID5 array. All my VMs are on the same LUN. ( 600GB) The other LUN is a RMD data disk(1.6TB) which is only used by one VM.

It looks like my free space is just below 25% you mentioned, but well over 20% other people mentioned.

Re: DS4000 SRM issues

FG0711 — Sat, 27 Jun 2009 01:38:51 GMT

Everybody, Thank you all for your feedback. It's very usefull. I'll follow many provided here suggestions some time next week.

Re: DS4000 SRM issues

KrishnaR — Tue, 23 Jun 2009 19:00:45 GMT

http://www-03.ibm.com/support/techdocs/atsmastr.nsf/WebIndex/WP101443

This IBM DS4k/5k SRA guide should be helpful. It's also present on the SRM site I think.

Re: DS4000 SRM issues

dex_1234 — Tue, 23 Jun 2009 18:15:15 GMT

As mentioned already, the latest SRA(may) removes the unconfigured disk requirement for flashcopies taken during test failover. Are you not seeing the mirror pair during Array Manager configuration? Mirror pairs with no virtual machine objects on it will not be reported. If you just configured mirroring and haven't yet configured a datastore with VMs on it, nothing will be reported during Array Manager configuration. Thought I'd just throw that out.

Re: DS4000 SRM issues

cj1223 — Tue, 23 Jun 2009 18:13:07 GMT

in response to previous post, the full link is http://daveveness.wordpress.com/2009/01/09/ibm-ds4700-model-70-vmware-esx-35-and-site-recovery-manager/

Re: DS4000 SRM issues

cj1223 — Tue, 23 Jun 2009 17:41:55 GMT

This reference proved to be very helpful with our installation of SRM using the DS 4700.

http://daveveness.wordpress.com/2009/01/09/ibm-d...odel-70-vmware-esx-35-and-site-recovery-manager

HTH.

Re: DS4000 SRM issues

TheGallowMan — Tue, 23 Jun 2009 11:56:57 GMT

The latest SRA (May 09) removes the requirement for unconfigured disks, It now just needs enough free space (25%) for the FlashCopy LUN to be created. In my experience when using DS4700s and SRM the biggest problems were getting the SRA to recognise the replicated LUNs. Once we enabled the Enhanced Remote Mirroring (both sites) and FlashCopy (recovery site) features were enabled and replicated LUNs configured we were OK.

Re: DS4000 SRM issues

mariab — Tue, 23 Jun 2009 11:19:44 GMT

Hi Felix,

Could you attach new SRM logs?

-Masha

Re: DS4000 SRM issues

Iuridae — Tue, 23 Jun 2009 06:17:21 GMT

Hi FG,

You will need empty, unassigned disk for each LUN you replicate. You will only need one if a disk has atleast 20% capacity of the replicated LUN.

ex. if you have a LUN with 1TB that you replicate and is gonna do a test failover, SRA will take one disk (or as many as needed) to create a new array 0 and LUN with 200gb space. This is done for each LUN that is part of the test. So if you have more LUN in the test, a new array/LUN is created for each.

Hope it makes sense.

Re: DS4000 SRM issues

FG0711 — Tue, 23 Jun 2009 04:35:54 GMT

I upgraded to the latest SRA and firmware versions and am using a single fabric. Still no go. Someone here mentioned that empty disks (not assigned to any arrays) as well as unconfigured space within an array are required. I am now thinking that I may not have sufficient unallocated storage space. I would appreciate any feedback on this. I only replicate 3 out of 6 LUNs.

Re: DS4000 SRM issues

dex_1234 — Fri, 19 Jun 2009 15:24:46 GMT

It'll be on the VMware site, the same location where you downloaded SRM software. New releases of the SRA will always be posted here. The current version of the SRA is, 01.01.35.01, make sure you read the readme for it. This version of the SRA will also support the new 7.50 controller firmware.

Re: DS4000 SRM issues

mariab — Fri, 19 Jun 2009 15:16:30 GMT

Hi Felix,

VMware's web site is the right place to download SRAs.

-Masha

Re: DS4000 SRM issues

FG0711 — Fri, 19 Jun 2009 15:02:41 GMT

Thanks for the help, everubody. I updated to firmvare 7.36. Where is the latest (may 09) IBM SRA located? ( vmware or ibm site?)

Re: DS4000 SRM issues

dex_1234 — Thu, 18 Jun 2009 16:23:26 GMT

The IBM SRA supports controller firmware 7.x and up. It does not support 6.X controller code. You'll have to upgrade controller firmware to 7.x before the SRA is able

to effectively communicate with the subsystem. Also, make sure you're using the latest IBM SRA as well. The newest one was released in May.

Re: DS4000 SRM issues

mariab — Thu, 18 Jun 2009 16:21:20 GMT

Hi Felix,

I just noticed that you have have "firmware ver 06.23.05". I believe the SRA doesn't support it and required firmware version 7.1 and up.

-Masha

Re: DS4000 SRM issues

FG0711 — Thu, 18 Jun 2009 16:07:23 GMT

my ESX hosts see all LUNs , i am using them without any issues. I just rescanned HBAs on both hosts and re-did the srm config for the SAN, but got the same result. I replicate only 2 ( #4 and $5) out of 5 LUNs. Both are RDM, one to a VM. Thanks

Re: DS4000 SRM issues

mariab — Thu, 18 Jun 2009 15:44:03 GMT

Hi Felix,

It looks like there are two replicated devices but they are not presented to any ESX hosts. Could you double check that?

1 Got a Mirrored LUN
1 LunMapping.mapRef is NULL
1 peerArrayId=600a0b80002ab45c0000000049704cb3
1 Got a Mirrored LUN
1 LunMapping.mapRef is NULL
1 peerArrayId=600a0b80002ab45c0000000049704cb3
...
~~2009-06-18 09:49:06.000 'PrimarySanProvider' 3332 trivia~~ 'discoverLuns' returned <?xml version="1.0" encoding="UTF-8"?>
1 <Response>
1 <InitiatorGroupList>
1 <InitiatorGroup id="85000000600a0b80002ab45a0036045a49edfd8b">
1 <Initiator id="2100001b3204f9df" type="FC" />
1 <Initiator id="2100001b32042bdf" type="FC" />
1 <Initiator id="2100001b32042cdf" type="FC" />
1 <Initiator id="2100001b320454e0" type="FC" />
1 </InitiatorGroup>
1 </InitiatorGroupList>
1 <LunList arrayId="600a0b80002ab4b00000000049704bef">
1 <Lun id="600a0b80002ab45a000006204a38b14d">
1 <Peer>
1 <ArrayKey>600a0b80002ab45c0000000049704cb3</ArrayKey>
1 <ReplicaLunKey>600a0b80002ab47c0000073549e89cbd</ReplicaLunKey>
1 </Peer>
1 </Lun>
1 <Lun id="600a0b80002ab4b0000006374a38af32">
1 <Peer>
1 <ArrayKey>600a0b80002ab45c0000000049704cb3</ArrayKey>
1 <ReplicaLunKey>600a0b80002ab45c0000074d49e89cb6</ReplicaLunKey>
1 </Peer>
1 </Lun>
1 </LunList>
1 <ReturnCode>0</ReturnCode>
1 </Response>

~~2009-06-18 09:49:06.000 'PrimarySanProvider' 3332 warning~~ Skipping LUN '600a0b80002ab45a000006204a38b14d' with neither WWN nor host numbers specified
~~2009-06-18 09:49:06.000 'PrimarySanProvider' 3332 warning~~ Skipping LUN '600a0b80002ab4b0000006374a38af32' with neither WWN nor host numbers specified

-Masha

Re: DS4000 SRM issues

FG0711 — Thu, 18 Jun 2009 15:20:19 GMT

masha,

thanks for your help. attached are : sra logfile and srm logfile. I did not see any issues. thank you-felix-

Re: DS4000 SRM issues

mariab — Thu, 18 Jun 2009 14:47:39 GMT

Hi,

It looks like SRA didn't find any replicated devices. SRA's log included in SRM's log may have more details. Could you attach SRM's log?

-Masha

Re: DS4000 SRM issues

FG0711 — Thu, 18 Jun 2009 14:31:49 GMT

I have a problem wih DS4700-70 ( firmware ver 06.23.05) and SRM 1.0 u1: when configuring array managers, SRM can communicate with each controller but does not find any LUNs and displays 0 in replicated arrays pairs. ERA installation went OK and I do not get any error mssages. I have two clustered hosts (ESX3.5U3) in each site that work fine with my storage. I would appreciate any advise. Could the controller's firmware version be a problem ?Thank you.

attached is a screenshot of the issue (.rtf file)

Re: DS4000 SRM issues

Iuridae — Tue, 21 Apr 2009 10:02:47 GMT

Hi Khani3,

I get a mail each time someone makes a reply

I was told that both HBA cards needs to see both controllers, since DS4700 only have one interface for host I had to setup a ISL between my SAN switches and merge the fabrics. But you can try without first.
You probably only need a ISL on your Primary Location since its the host located there that need to see the controllers.

SRA creates a RAID0 disk and allocates 20% of the replicated LUN. So if you have 1TB LUN you will need 200gb for test failover (If i rememberd correctly). We had 450gb disks and 1.6TB LUN and that was enough when we did a Test Failover.

If you have 6 replicated LUNs and will do a test on all at the same time you will need 6 empty disks, regardless of size. This was with the version of SRA we used, i was told this would be fixed in a later release. Dont know status of that now, but it was in January this year I configured it. (1.35.00.07?)

/ iuridae

Re: DS4000 SRM issues

khani3 — Tue, 21 Apr 2009 09:48:19 GMT

Luridae

Thanks, that was quick.

Is their no other way - because i have been told that you can do with 1 HBA seeing only 1 controller and the other HBA seeing the other controller.

Also will i have to merge fabrics at both ends or just the primary location?

How much empty disks do i need to leave as i have around 1 TB for exchange (6 Luns), I was planning on just putting in 2 additional 750 GB disks. Is it per lun?

Imran

Re: DS4000 SRM issues

Iuridae — Tue, 21 Apr 2009 09:36:47 GMT

Hi Khani3.

Yes, i had to merge the two fabric into one to make it work. Also, i had to leave empty disks on the DS4700 to be able to do a Test Failover since the SRA uses one disk for each replicated to LUN for flash copy.

Hope it helps.

Re: DS4000 SRM issues

khani3 — Tue, 21 Apr 2009 09:28:43 GMT

Hi I have a bit of a problem and you might be able to help

I have 2 * DS4700 model 70 (2 drive channels) - 1 for production and 1 for DR

One port on each controller is needed for replication so that leaves 1 port on each controller A and B

I have 2 switches that take one each port from the controller. These are presented to the ESX host HBA 1 and HBA 2

So controller A0 port is presented to HBA 1 and Controller B0 port is presented to HBA 2 on the ESX host. In order for SRM to work will this be ok?

I read in best practice that both HBA need to be able to see both controller, but is it a must.

I dont want to merge the fabrics together but if i have no other choice then i might have to

I like to thank you in advance for any help you do priovide

Imran

Re: DS4000 SRM issues

KrishnaR — Fri, 20 Feb 2009 22:46:59 GMT

This was a local build intended to be a possible hotfix to an issue. There are later versions which are in test now. Please PM me for details.

Re: DS4000 SRM issues

iefke — Thu, 19 Feb 2009 19:15:41 GMT

From IBM we got SRA 01.00.35.09

www.ivobeerens.nl

Re: DS4000 SRM issues

KrishnaR — Thu, 19 Feb 2009 18:46:00 GMT

What version of SRA did you get from IBM?

Re: DS4000 SRM issues

iefke — Thu, 19 Feb 2009 17:16:59 GMT

here is the SRM recovery plan log:

2. Prepare Storage	Error: Non-fatal error information reported during execution of array integration script: testFailover Output: 2009-02-13:: 13:47:54:INFO:main:Command is testFailover2009-02-13:: 13:47:54:INFO:main:Calling failover :: Command "C:\Program Files\VMware\VMware Site Recovery Manager\external\perl-5.8.8\bin\perl.exe" "C:/Program Files/VMware/VMware Site Recovery Manager/scripts/SAN/IBM/failover.pl" temp46122009-02-13:: 13:47:54:QUITE:main:Logging data for failover2009-02-13:: 13:47:54:INFO:failover:Parsing the failover input.....2009-02-13:: 13:47:54:INFO:testFailover:Parsing the testFailover input.....2009-02-13:: 13:47:54:INFO:MAIN:Entry (2009-02-13 01:47:54) ~~.\cli\sraLogger.cpp:182~~::INFO::SMsra::Initializing SRA Logger with Params: LogType=Priority-based logging LogLevel=INFO LogStore=STDOUT LogFileName=Main_3196.trc DumpFileName= InitStatus=1(2009-02-13 01:47:54) ~~.\cli\sraCli.cpp:347~~::INFO::SMsra::Cli::main::START(2009-02-13 01:47:54) ~~.\cli\sraLogger.cpp:182~~::INFO::SMsra::Initializing SRA Logger with Params: LogType=Priority-based logging LogLevel=TRIVIA LogStore=STDOUT LogFileName=testFailover_3196.trc DumpFileName= InitStatus=1(2009-02-13 01:47:54) ~~.\cli\sraCli.cpp:400~~::INFO::SMsra::Cli::main::Command is testFailover(2009-02-13 01:47:54) ~~.\cli\sraCli.cpp:439~~::INFO::SMsra::Cli::main::Starting parsing of input args...(2009-02-13 01:47:54) ~~.\cli\sraTestFailover.cpp:75~~::TRIVIA::SMsra::TestFailover::parseInputArgs::Entry(2009-02-13 01:47:54) ~~.\cli\sraTestFailover.cpp:84~~::VERBOSE::SMsra::TestFailover::parseInputArgs::No of args = 31(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:301~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::InStr=iScsi-fc-all(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:313~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::OutStr=iScsi-fc-all(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:301~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::InStr=21:00:00:1b:32:1b:94:49(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:313~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::OutStr=2100001b321b9449(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:301~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::InStr=21:00:00:1b:32:1b:ea:4a(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:313~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::OutStr=2100001b321bea4a(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:301~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::InStr=21:00:00:1b:32:1b:46:49(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:313~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::OutStr=2100001b321b4649(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:301~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::InStr=21:00:00:1b:32:1a:d3:d5(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:313~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::OutStr=2100001b321ad3d5(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:301~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::InStr=iScsi-fc-all(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:313~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::OutStr=iScsi-fc-all(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:301~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::InStr=iScsi-fc-all(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:313~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::OutStr=iScsi-fc-all(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:301~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::InStr=iScsi-fc-all(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:313~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::OutStr=iScsi-fc-all(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:301~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::InStr=iScsi-fc-all(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:313~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::OutStr=iScsi-fc-all(2009-02-13 01:47:54) ~~.\cli\sraTestFailover.cpp:233~~::TRIVIA::SMsra::TestFailover::parseInputArgs::Exit(2009-02-13 01:47:54) ~~.\cli\sraCli.cpp:441~~::INFO::SMsra::Cli::main::Perform testFailover Operation...(2009-02-13 01:47:54) ~~.\cli\sraTestFailover.cpp:266~~::VERBOSE::SMsra::TestFailover::performOp::EntrybindToController succesfullCurrent CGN=29502(2009-02-13 01:47:55) ~~.\cli\sraTestFailover.cpp:302~~::TRIVIA::SMsra::TestFailover::performOp::Calling tfoStart(2009-02-13 01:47:55) ~~.\cli\sraTestFailover.cpp:355~~::TRIVIA::SMsra::TestFailover::toStart::Entry(2009-02-13 01:47:55) ~~.\cli\sraTestFailover.cpp:1170~~::VERBOSE::SMsra::TestFailover::getVolumeWithWWN::Got Volume with WWN 600a0b80004771f40000f19a49797e87(2009-02-13 01:47:55) ~~.\cli\sraTestFailover.cpp:386~~::VERBOSE::SMsra::TestFailover::toStart::Got Volume(2009-02-13 01:47:55) ~~.\cli\sraTestFailover.cpp:401~~::VERBOSE::SMsra::TestFailover::toStart::Volume status is Optimal(2009-02-13 01:47:55) ~~.\cli\sraTestFailover.cpp:411~~::VERBOSE::SMsra::TestFailover::toStart::Snapshot for Volume not present, Creating Snapshot(2009-02-13 01:47:55) ~~.\cli\sraTestFailover.cpp:1507~~::VERBOSE::SMsra::Next Snapshot Count=0bindToController succesfullCurrent CGN=29502(2009-02-13 01:47:56) ~~.\cli\sraTestFailover.cpp:1228~~::TRIVIA::SMsra::TestFailover::createSnapshot::Got candidates for Snapshot request 1(2009-02-13 01:47:56) ~~.\cli\sraTestFailover.cpp:1274~~::TRIVIA::SMsra::TestFailover::createSnapshot::Start of createSnapshotbindToController succesfullCurrent CGN=29502(2009-02-13 01:47:56) ~~.\cli\sraTestFailover.cpp:1295~~::ERROR::SMsra::TestFailover::createSnapshot::Failed to create Snapshot! ReturnCode 13(2009-02-13 01:47:56) ~~.\cli\sraTestFailover.cpp:1299~~::INFO::SMsra::TestFailover::createSnapshot::CreateSnapshot failed with RETCODE_TRY_ALTERNATE.. Retry...(2009-02-13 01:47:56) ~~.\cli\sraStorageArrayCommandExecutor.cpp:328~~::TRIVIA::SMsra::StorageArrayCommandExecutor::connectToAlternateCtrl::Entry(2009-02-13 01:47:56) ~~.\cli\sraStorageArrayCommandExecutor.cpp:331~~::INFO::SMsra::StorageArrayCommandExecutor::connectToAlternateCtrl::Old Ctrl Ref=070000000000000000000002 :: Old IP=10.15.254.209(2009-02-13 01:47:56) ~~.\cli\sraStorageArrayCommandExecutor.cpp:345~~::TRIVIA::SMsra::StorageArrayCommandExecutor::connectToAlternateCtrl::Alternate connection estb with IP 10.15.254.205(2009-02-13 01:47:56) ~~.\cli\sraStorageArrayCommandExecutor.cpp:349~~::TRIVIA::SMsra::StorageArrayCommandExecutor::connectToAlternateCtrl::Discovered a controller at IP 10.15.254.205(2009-02-13 01:47:56) ~~.\cli\sraStorageArrayCommandExecutor.cpp:360~~::TRIVIA::SMsra::StorageArrayCommandExecutor::connectToAlternateCtrl::Connected to the same array via alternate path(2009-02-13 01:47:56) ~~.\cli\sraStorageArrayCommandExecutor.cpp:363~~::TRIVIA::SMsra::StorageArrayCommandExecutor::connectToAlternateCtrl:: New Ctrl Ref=070000000000000000000001 :: Old Ctrl Ref=070000000000000000000002(2009-02-13 01:47:56) ~~.\cli\sraStorageArrayCommandExecutor.cpp:366~~::VERBOSE::SMsra::StorageArrayCommandExecutor::connectToAlternateCtrl::Setting up Alternate Controller params(2009-02-13 01:47:56) ~~.\cli\sraStorageArrayCommandExecutor.cpp:371~~::VERBOSE::SMsra::StorageArrayCommandExecutor::connectToAlternateCtrl::Connected to new IPbindToController succesfullCurrent CGN=29502(2009-02-13 01:47:57) ~~.\cli\sraStorageArrayCommandExecutor.cpp:377~~::INFO::SMsra::StorageArrayCommandExecutor::connectToAlternateCtrl:: Set new ctrl ref=070000000000000000000001 :: Set new IP=10.15.254.205bindToController succesfullCurrent CGN=29502(2009-02-13 01:47:59) ~~.\cli\sraTestFailover.cpp:1332~~::TRIVIA::SMsra::TestFailover::createSnapshot::Snapshot creation succesfull.. Exit true(2009-02-13 01:47:59) ~~.\cli\sraTestFailover.cpp:424~~::VERBOSE::SMsra::TestFailover::toStart::createSnapshot returned, updating ObjectGraphbindToController succesfullCurrent CGN=29503(2009-02-13 01:47:59) ~~.\cli\sraTestFailover.cpp:429~~::VERBOSE::SMsra::TestFailover::toStart::Got new ObjectGraph, trying to validate the new Snapshot Volume(2009-02-13 01:47:59) ~~.\cli\sraTestFailover.cpp:1453~~::TRIVIA::SMsra::TestFailover::toStart::Snapshot Volume drsra-snap-0 exists(2009-02-13 01:47:59) ~~.\cli\sraTestFailover.cpp:1454~~::TRIVIA::SMsra::TestFailover::toStart::Snapshot Volume Status:1(2009-02-13 01:47:59) ~~.\cli\sraTestFailover.cpp:1455~~::TRIVIA::SMsra::TestFailover::toStart::Snapshot Volume Action:1(2009-02-13 01:47:59) ~~.\cli\sraTestFailover.cpp:1456~~::TRIVIA::SMsra::TestFailover::toStart::Base Volume Status:1(2009-02-13 01:47:59) ~~.\cli\sraTestFailover.cpp:1457~~::TRIVIA::SMsra::TestFailover::toStart::Base Volume Status:1(2009-02-13 01:47:59) ~~.\cli\sraTestFailover.cpp:433~~::TRIVIA::SMsra::TestFailover::toStart::Snapshot Volume exists(2009-02-13 01:47:59) ~~.\cli\sraTestFailover.cpp:447~~::VERBOSE::SMsra::TestFailover::toStart::Found snapshot volume just created(2009-02-13 01:47:59) ~~.\cli\sraTestFailover.cpp:455~~::TRIVIA::SMsra::TestFailover::toStart::Found a mapping for Base Volume(2009-02-13 01:47:59) ~~.\cli\sraTestFailover.cpp:464~~::VERBOSE::SMsra::TestFailover::toStart::Trying to create a mapping with Base Volume Initiator/InitiatorGroupbindToController succesfullCurrent CGN=29503(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 0(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 1(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 3(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 12(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 2(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 4(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 5(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 6(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 7(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 8(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 9(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 10(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 11(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 111(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 108(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 109(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 107(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 101(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 103(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 102(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 100(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 106(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 105(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 110(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 104(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1654~~::INFO::SMsra::Returning LunNumber as 13(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:472~~::VERBOSE::SMsra::TestFailover::toStart::New Lun Number generated is 13bindToController succesfullCurrent CGN=29503(2009-02-13 01:48:01) ~~.\cli\sraTestFailover.cpp:487~~::INFO::SMsra::TestFailover::toStart::Created a LUNMapping between snapshotVolume and Base Volume I/IG(2009-02-13 01:48:01) ~~.\cli\sraTestFailover.cpp:491~~::VERBOSE::SMsra::TestFailover::toStart::Done creating Mapping with base volume I/IG, checking LunAccess(2009-02-13 01:48:01) ~~.\cli\sraTestFailover.cpp:503~~::VERBOSE::SMsra::TestFailover::toStart::Checking if ReplicaLunKey 600a0b80004752200000f1884979823b matches the base Volume WWN(2009-02-13 01:48:01) ~~.\cli\sraTestFailover.cpp:503~~::VERBOSE::SMsra::TestFailover::toStart::Checking if ReplicaLunKey 600a0b80004771f40000f19a49797e87 matches the base Volume WWN(2009-02-13 01:48:01) ~~.\cli\sraTestFailover.cpp:513~~::VERBOSE::SMsra::TestFailover::toStart::Get the initiatorGroup object based on the Id(2009-02-13 01:48:01) ~~.\cli\sraTestFailover.cpp:1379~~::TRIVIA::SMsra::TestFailover::getInitiatorGroupWithId::Entry with initiatorGroupId=iScsi-fc-all(2009-02-13 01:48:01) ~~.\cli\sraTestFailover.cpp:1402~~::TRIVIA::SMsra::TestFailover::getInitiatorGroupWithId::Exit as false(2009-02-13 01:48:01) ~~.\cli\sraTestFailover.cpp:530~~::INFO::SMsra::TestFailover::toStart::Not found InitiatorGroup Object from ObjectBundle(2009-02-13 01:48:01) ~~.\cli\sraTestFailover.cpp:537~~::INFO::SMsra::TestFailover::toStart::Got InitiatorGroup from Command itself... Processing Initiator list(2009-02-13 01:48:01) ~~.\cli\sraTestFailover.cpp:1515~~::TRIVIA::SMsra::TestFailover::getInitiatorWithId::Entry with initId 2100001b321b9449(2009-02-13 01:48:01) ~~.\cli\sraTestFailover.cpp:1523~~::VERBOSE::SMsra::TestFailover::getInitiatorWithId::Got an initiator(2009-02-13 01:48:01) ~~.\cli\sraTestFailover.cpp:546~~::VERBOSE::SMsra::TestFailover::toStart::Preparing for createLUNMapping with Initiator object 2100001b321b9449...(2009-02-13 01:48:01) ~~.\cli\sraTestFailover.cpp:1343~~::TRIVIA::SMsra::TestFailover::createLunMapping::EntrybindToController succesfullCurrent CGN=29504(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1559~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::symRef is a Host(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1582~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Host associated to a CLUSTER(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 0(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 1(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 3(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 12(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 2(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 4(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 5(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 6(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 7(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 8(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 9(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 10(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 11(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 111(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 108(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 109(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 107(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 101(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 103(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 102(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 100(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 106(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 105(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 110(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 104(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 13(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1654~~::INFO::SMsra::Returning LunNumber as 14(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1349~~::VERBOSE::SMsra::TestFailover::createLunMapping::Got newLunNumber as 14bindToController succesfullCurrent CGN=29504(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1357~~::TRIVIA::SMsra::TestFailover::createLunMapping::createLunMapping returned(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1361~~::ERROR::SMsra::TestFailover::createLunMapping::Failover complete but create LUNMapping failed for with ReturnCode 63(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:553~~::VERBOSE::SMsra::TestFailover::toStart::createLunMapping failed, going to next initiatorId...(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1515~~::TRIVIA::SMsra::TestFailover::getInitiatorWithId::Entry with initId 2100001b321bea4a(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1523~~::VERBOSE::SMsra::TestFailover::getInitiatorWithId::Got an initiator(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:546~~::VERBOSE::SMsra::TestFailover::toStart::Preparing for createLUNMapping with Initiator object 2100001b321bea4a...(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1343~~::TRIVIA::SMsra::TestFailover::createLunMapping::EntrybindToController succesfullCurrent CGN=29504(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1559~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::symRef is a Host(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1582~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Host associated to a CLUSTER(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 0(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 1(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 3(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 12(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 2(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 4(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 5(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 6(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 7(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 8(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 9(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 10(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 11(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 111(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 108(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 109(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 107(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 101(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 103(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 102(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 100(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 106(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 105(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 110(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 104(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 13(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1654~~::INFO::SMsra::Returning LunNumber as 14(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1349~~::VERBOSE::SMsra::TestFailover::createLunMapping::Got newLunNumber as 14bindToController succesfullCurrent CGN=29504(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1357~~::TRIVIA::SMsra::TestFailover::createLunMapping::createLunMapping returned(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1361~~::ERROR::SMsra::TestFailover::createLunMapping::Failover complete but create LUNMapping failed for with ReturnCode 63(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:553~~::VERBOSE::SMsra::TestFailover::toStart::createLunMapping failed, going to next initiatorId...(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1515~~::TRIVIA::SMsra::TestFailover::getInitiatorWithId::Entry with initId 2100001b321b4649(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1523~~::VERBOSE::SMsra::TestFailover::getInitiatorWithId::Got an initiator(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:546~~::VERBOSE::SMsra::TestFailover::toStart::Preparing for createLUNMapping with Initiator object 2100001b321b4649...(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1343~~::TRIVIA::SMsra::TestFailover::createLunMapping::EntrybindToController succesfullCurrent CGN=29504(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1559~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::symRef is a Host(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1582~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Host associated to a CLUSTER(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 0(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 1(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 3(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 12(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 2(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 4(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 5(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 6(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 7(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 8(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 9(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 10(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 11(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 111(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 108(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 109(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 107(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 101(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 103(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 102(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 100(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 106(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 105(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 110(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 104(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 13(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1654~~::INFO::SMsra::Returning LunNumber as 14(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1349~~::VERBOSE::SMsra::TestFailover::createLunMapping::Got newLunNumber as 14bindToController succesfullCurrent CGN=29504(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1357~~::TRIVIA::SMsra::TestFailover::createLunMapping::createLunMapping returned(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1361~~::ERROR::SMsra::TestFailover::createLunMapping::Failover complete but create LUNMapping failed for with ReturnCode 63(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:553~~::VERBOSE::SMsra::TestFailover::toStart::createLunMapping failed, going to next initiatorId...(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1515~~::TRIVIA::SMsra::TestFailover::getInitiatorWithId::Entry with initId 2100001b321ad3d5(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1523~~::VERBOSE::SMsra::TestFailover::getInitiatorWithId::Got an initiator(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:546~~::VERBOSE::SMsra::TestFailover::toStart::Preparing for createLUNMapping with Initiator object 2100001b321ad3d5...(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1343~~::TRIVIA::SMsra::TestFailover::createLunMapping::EntrybindToController succesfullCurrent CGN=29504(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1559~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::symRef is a Host(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1582~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Host associated to a CLUSTER(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 0(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 1(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 3(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 12(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 2(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 4(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 5(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 6(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 7(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 8(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 9(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 10(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 11(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 111(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 108(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 109(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 107(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 101(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 103(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 102(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 100(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 106(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 105(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 110(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 104(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 13(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1654~~::INFO::SMsra::Returning LunNumber as 14(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1349~~::VERBOSE::SMsra::TestFailover::createLunMapping::Got newLunNumber as 14bindToController succesfullCurrent CGN=29504(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1357~~::TRIVIA::SMsra::TestFailover::createLunMapping::createLunMapping returned(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1361~~::ERROR::SMsra::TestFailover::createLunMapping::Failover complete but create LUNMapping failed for with ReturnCode 63(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:553~~::VERBOSE::SMsra::TestFailover::toStart::createLunMapping failed, going to next initiatorId...(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:503~~::VERBOSE::SMsra::TestFailover::toStart::Checking if ReplicaLunKey 600a0b80004752200000f1884979823b matches the base Volume WWN(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:503~~::VERBOSE::SMsra::TestFailover::toStart::Checking if ReplicaLunKey 600a0b80004771f40000f19a49797e87 matches the base Volume WWN(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:513~~::VERBOSE::SMsra::TestFailover::toStart::Get the initiatorGroup object based on the Id(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1379~~::TRIVIA::SMsra::TestFailover::getInitiatorGroupWithId::Entry with initiatorGroupId=iScsi-fc-all(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1402~~::TRIVIA::SMsra::TestFailover::getInitiatorGroupWithId::Exit as false(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:530~~::INFO::SMsra::TestFailover::toStart::Not found InitiatorGroup Object from ObjectBundle(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:537~~::INFO::SMsra::TestFailover::toStart::Got InitiatorGroup from Command itself... Processing Initiator list(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1515~~::TRIVIA::SMsra::TestFailover::getInitiatorWithId::Entry with initId 2100001b321b9449(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1523~~::VERBOSE::SMsra::TestFailover::getInitiatorWithId::Got an initiator(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:546~~::VERBOSE::SMsra::TestFailover::toStart::Preparing for createLUNMapping with Initiator object 2100001b321b9449...(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1343~~::TRIVIA::SMsra::TestFailover::createLunMapping::EntrybindToController succesfullCurrent CGN=29504(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1559~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::symRef is a Host(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1582~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Host associated to a CLUSTER(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 0(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 1(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 3(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 12(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 2(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 4(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 5(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 6(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 7(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 8(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 9(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 10(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 11(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 111(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 108(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 109(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 107(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 101(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 103(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 102(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 100(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 106(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 105(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 110(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 104(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 13(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1654~~::INFO::SMsra::Returning LunNumber as 14(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1349~~::VERBOSE::SMsra::TestFailover::createLunMapping::Got newLunNumber as 14bindToController succesfullCurrent CGN=29504(2009-02-13 01:48:07) ~~.\cli\sraTestFailover.cpp:1357~~::TRIVIA::SMsra::TestFailover::createLunMapping::createLunMapping returned(2009-02-13 01:48:07) ~~.\cli\sraTestFailover.cpp:1361~~::ERROR::SMsra::TestFailover::createLunMapping::Failover complete but create LUNMapping failed for with ReturnCode 63(2009-02-13 01:48:07) ~~.\cli\sraTestFailover.cpp:553~~::VERBOSE::SMsra::TestFailover::toStart::createLunMapping failed, going to next initiatorId...(2009-02-13 01:48:07) ~~.\cli\sraTestFailover.cpp:1515~~::TRIVIA::SMsra::TestFailover::getInitiatorWithId::Entry with initId 2100001b321bea4a(2009-02-13 01:48:07) ~~.\cli\sraTestFailover.cpp:1523~~::VERBOSE::SMsra::TestFailover::getInitiatorWithId::Got an initiator(2009-02-13 01:48:07) ~~.\cli\sraTestFailover.cpp:546~~::VERBOSE::SMsra::TestFailover::toStart::Preparing for createLUNMapping with Initiator object 2100001b321bea4a...(2009-02-13 01:48:07) ~~.\cli\sraTestFailover.cpp:1343~~::TRIVIA::SMsra::TestFailover::createLunMapping::EntrybindToController succesfullCurrent CGN=29504(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1559~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::symRef is a Host(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1582~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Host associated to a CLUSTER(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 0(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 1(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 3(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 12(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 2(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 4(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 5(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 6(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 7(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 8(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 9(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 10(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 11(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 111(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 108(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 109(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 107(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 101(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 103(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 102(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 100(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 106(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 105(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 110(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 104(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 13(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1654~~::INFO::SMsra::Returning LunNumber as 14(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1349~~::VERBOSE::SMsra::TestFailover::createLunMapping::Got newLunNumber as 14bindToController succesfullCurrent CGN=29504(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1357~~::TRIVIA::SMsra::TestFailover::createLunMapping::createLunMapping returned(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1361~~::ERROR::SMsra::TestFailover::createLunMapping::Failover complete but create LUNMapping failed for with ReturnCode 63(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:553~~::VERBOSE::SMsra::TestFailover::toStart::createLunMapping failed, going to next initiatorId...(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1515~~::TRIVIA::SMsra::TestFailover::getInitiatorWithId::Entry with initId 2100001b321b4649(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1523~~::VERBOSE::SMsra::TestFailover::getInitiatorWithId::Got an initiator(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:546~~::VERBOSE::SMsra::TestFailover::toStart::Preparing for createLUNMapping with Initiator object 2100001b321b4649...(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1343~~::TRIVIA::SMsra::TestFailover::createLunMapping::EntrybindToController succesfullCurrent CGN=29504(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1559~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::symRef is a Host(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1582~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Host associated to a CLUSTER(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 0(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 1(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 3(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 12(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 2(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 4(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 5(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 6(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 7(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 8(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 9(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 10(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 11(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 111(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 108(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 109(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 107(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 101(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 103(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 102(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 100(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 106(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 105(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 110(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 104(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 13(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1654~~::INFO::SMsra::Returning LunNumber as 14(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1349~~::VERBOSE::SMsra::TestFailover::createLunMapping::Got newLunNumber as 14bindToController succesfullCurrent CGN=29504(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1357~~::TRIVIA::SMsra::TestFailover::createLunMapping::createLunMapping returned(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1361~~::ERROR::SMsra::TestFailover::createLunMapping::Failover complete but create LUNMapping failed for with ReturnCode 63(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:553~~::VERBOSE::SMsra::TestFailover::toStart::createLunMapping failed, going to next initiatorId...(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1515~~::TRIVIA::SMsra::TestFailover::getInitiatorWithId::Entry with initId 2100001b321ad3d5(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1523~~::VERBOSE::SMsra::TestFailover::getInitiatorWithId::Got an initiator(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:546~~::VERBOSE::SMsra::TestFailover::toStart::Preparing for createLUNMapping with Initiator object 2100001b321ad3d5...(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1343~~::TRIVIA::SMsra::TestFailover::createLunMapping::EntrybindToController succesfullCurrent CGN=29504(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1559~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::symRef is a Host(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1582~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Host associated to a CLUSTER(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 0(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 1(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 3(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 12(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 2(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 4(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 5(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 6(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 7(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 8(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 9(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 10(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 11(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 111(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 108(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 109(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 107(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 101(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 103(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 102(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 100(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 106(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 105(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 110(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 104(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 13(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1654~~::INFO::SMsra::Returning LunNumber as 14(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1349~~::VERBOSE::SMsra::TestFailover::createLunMapping::Got newLunNumber as 14bindToController succesfullCurrent CGN=29504(2009-02-13 01:48:11) ~~.\cli\sraTestFailover.cpp:1357~~::TRIVIA::SMsra::TestFailover::createLunMapping::createLunMapping returned(2009-02-13 01:48:11) ~~.\cli\sraTestFailover.cpp:1361~~::ERROR::SMsra::TestFailover::createLunMapping::Failover complete but create LUNMapping failed for with ReturnCode 63(2009-02-13 01:48:11) ~~.\cli\sraTestFailover.cpp:553~~::VERBOSE::SMsra::TestFailover::toStart::createLunMapping failed, going to next initiatorId...(2009-02-13 01:48:11) ~~.\cli\sraTestFailover.cpp:1170~~::VERBOSE::SMsra::TestFailover::getVolumeWithWWN::Got Volume with WWN 600a0b80004752200000f1884979823b(2009-02-13 01:48:11) ~~.\cli\sraTestFailover.cpp:386~~::VERBOSE::SMsra::TestFailover::toStart::Got Volume(2009-02-13 01:48:11) ~~.\cli\sraTestFailover.cpp:401~~::VERBOSE::SMsra::TestFailover::toStart::Volume status is Optimal(2009-02-13 01:48:11) ~~.\cli\sraTestFailover.cpp:411~~::VERBOSE::SMsra::TestFailover::toStart::Snapshot for Volume not present, Creating Snapshot(2009-02-13 01:48:11) ~~.\cli\sraTestFailover.cpp:1507~~::VERBOSE::SMsra::Next Snapshot Count=1bindToController succesfullCurrent CGN=295042009-02-13:: 13:48:20:INFO:main:Done with failover Error: .	00:00:36
2.1. Attach Disks for Protection Group "PG01"	Error: Non-fatal error information reported during execution of array integration script: testFailover Output: 2009-02-13:: 13:47:54:INFO:main:Command is testFailover2009-02-13:: 13:47:54:INFO:main:Calling failover :: Command "C:\Program Files\VMware\VMware Site Recovery Manager\external\perl-5.8.8\bin\perl.exe" "C:/Program Files/VMware/VMware Site Recovery Manager/scripts/SAN/IBM/failover.pl" temp46122009-02-13:: 13:47:54:QUITE:main:Logging data for failover2009-02-13:: 13:47:54:INFO:failover:Parsing the failover input.....2009-02-13:: 13:47:54:INFO:testFailover:Parsing the testFailover input.....2009-02-13:: 13:47:54:INFO:MAIN:Entry (2009-02-13 01:47:54) ~~.\cli\sraLogger.cpp:182~~::INFO::SMsra::Initializing SRA Logger with Params: LogType=Priority-based logging LogLevel=INFO LogStore=STDOUT LogFileName=Main_3196.trc DumpFileName= InitStatus=1(2009-02-13 01:47:54) ~~.\cli\sraCli.cpp:347~~::INFO::SMsra::Cli::main::START(2009-02-13 01:47:54) ~~.\cli\sraLogger.cpp:182~~::INFO::SMsra::Initializing SRA Logger with Params: LogType=Priority-based logging LogLevel=TRIVIA LogStore=STDOUT LogFileName=testFailover_3196.trc DumpFileName= InitStatus=1(2009-02-13 01:47:54) ~~.\cli\sraCli.cpp:400~~::INFO::SMsra::Cli::main::Command is testFailover(2009-02-13 01:47:54) ~~.\cli\sraCli.cpp:439~~::INFO::SMsra::Cli::main::Starting parsing of input args...(2009-02-13 01:47:54) ~~.\cli\sraTestFailover.cpp:75~~::TRIVIA::SMsra::TestFailover::parseInputArgs::Entry(2009-02-13 01:47:54) ~~.\cli\sraTestFailover.cpp:84~~::VERBOSE::SMsra::TestFailover::parseInputArgs::No of args = 31(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:301~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::InStr=iScsi-fc-all(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:313~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::OutStr=iScsi-fc-all(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:301~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::InStr=21:00:00:1b:32:1b:94:49(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:313~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::OutStr=2100001b321b9449(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:301~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::InStr=21:00:00:1b:32:1b:ea:4a(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:313~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::OutStr=2100001b321bea4a(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:301~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::InStr=21:00:00:1b:32:1b:46:49(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:313~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::OutStr=2100001b321b4649(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:301~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::InStr=21:00:00:1b:32:1a:d3:d5(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:313~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::OutStr=2100001b321ad3d5(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:301~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::InStr=iScsi-fc-all(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:313~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::OutStr=iScsi-fc-all(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:301~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::InStr=iScsi-fc-all(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:313~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::OutStr=iScsi-fc-all(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:301~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::InStr=iScsi-fc-all(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:313~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::OutStr=iScsi-fc-all(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:301~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::InStr=iScsi-fc-all(2009-02-13 01:47:54) ~~.\cli\sraStorageArrayCommandExecutor.cpp:313~~::TRIVIA::SMsra::StorageArrayCommandExecutor::formatId::OutStr=iScsi-fc-all(2009-02-13 01:47:54) ~~.\cli\sraTestFailover.cpp:233~~::TRIVIA::SMsra::TestFailover::parseInputArgs::Exit(2009-02-13 01:47:54) ~~.\cli\sraCli.cpp:441~~::INFO::SMsra::Cli::main::Perform testFailover Operation...(2009-02-13 01:47:54) ~~.\cli\sraTestFailover.cpp:266~~::VERBOSE::SMsra::TestFailover::performOp::EntrybindToController succesfullCurrent CGN=29502(2009-02-13 01:47:55) ~~.\cli\sraTestFailover.cpp:302~~::TRIVIA::SMsra::TestFailover::performOp::Calling tfoStart(2009-02-13 01:47:55) ~~.\cli\sraTestFailover.cpp:355~~::TRIVIA::SMsra::TestFailover::toStart::Entry(2009-02-13 01:47:55) ~~.\cli\sraTestFailover.cpp:1170~~::VERBOSE::SMsra::TestFailover::getVolumeWithWWN::Got Volume with WWN 600a0b80004771f40000f19a49797e87(2009-02-13 01:47:55) ~~.\cli\sraTestFailover.cpp:386~~::VERBOSE::SMsra::TestFailover::toStart::Got Volume(2009-02-13 01:47:55) ~~.\cli\sraTestFailover.cpp:401~~::VERBOSE::SMsra::TestFailover::toStart::Volume status is Optimal(2009-02-13 01:47:55) ~~.\cli\sraTestFailover.cpp:411~~::VERBOSE::SMsra::TestFailover::toStart::Snapshot for Volume not present, Creating Snapshot(2009-02-13 01:47:55) ~~.\cli\sraTestFailover.cpp:1507~~::VERBOSE::SMsra::Next Snapshot Count=0bindToController succesfullCurrent CGN=29502(2009-02-13 01:47:56) ~~.\cli\sraTestFailover.cpp:1228~~::TRIVIA::SMsra::TestFailover::createSnapshot::Got candidates for Snapshot request 1(2009-02-13 01:47:56) ~~.\cli\sraTestFailover.cpp:1274~~::TRIVIA::SMsra::TestFailover::createSnapshot::Start of createSnapshotbindToController succesfullCurrent CGN=29502(2009-02-13 01:47:56) ~~.\cli\sraTestFailover.cpp:1295~~::ERROR::SMsra::TestFailover::createSnapshot::Failed to create Snapshot! ReturnCode 13(2009-02-13 01:47:56) ~~.\cli\sraTestFailover.cpp:1299~~::INFO::SMsra::TestFailover::createSnapshot::CreateSnapshot failed with RETCODE_TRY_ALTERNATE.. Retry...(2009-02-13 01:47:56) ~~.\cli\sraStorageArrayCommandExecutor.cpp:328~~::TRIVIA::SMsra::StorageArrayCommandExecutor::connectToAlternateCtrl::Entry(2009-02-13 01:47:56) ~~.\cli\sraStorageArrayCommandExecutor.cpp:331~~::INFO::SMsra::StorageArrayCommandExecutor::connectToAlternateCtrl::Old Ctrl Ref=070000000000000000000002 :: Old IP=10.15.254.209(2009-02-13 01:47:56) ~~.\cli\sraStorageArrayCommandExecutor.cpp:345~~::TRIVIA::SMsra::StorageArrayCommandExecutor::connectToAlternateCtrl::Alternate connection estb with IP 10.15.254.205(2009-02-13 01:47:56) ~~.\cli\sraStorageArrayCommandExecutor.cpp:349~~::TRIVIA::SMsra::StorageArrayCommandExecutor::connectToAlternateCtrl::Discovered a controller at IP 10.15.254.205(2009-02-13 01:47:56) ~~.\cli\sraStorageArrayCommandExecutor.cpp:360~~::TRIVIA::SMsra::StorageArrayCommandExecutor::connectToAlternateCtrl::Connected to the same array via alternate path(2009-02-13 01:47:56) ~~.\cli\sraStorageArrayCommandExecutor.cpp:363~~::TRIVIA::SMsra::StorageArrayCommandExecutor::connectToAlternateCtrl:: New Ctrl Ref=070000000000000000000001 :: Old Ctrl Ref=070000000000000000000002(2009-02-13 01:47:56) ~~.\cli\sraStorageArrayCommandExecutor.cpp:366~~::VERBOSE::SMsra::StorageArrayCommandExecutor::connectToAlternateCtrl::Setting up Alternate Controller params(2009-02-13 01:47:56) ~~.\cli\sraStorageArrayCommandExecutor.cpp:371~~::VERBOSE::SMsra::StorageArrayCommandExecutor::connectToAlternateCtrl::Connected to new IPbindToController succesfullCurrent CGN=29502(2009-02-13 01:47:57) ~~.\cli\sraStorageArrayCommandExecutor.cpp:377~~::INFO::SMsra::StorageArrayCommandExecutor::connectToAlternateCtrl:: Set new ctrl ref=070000000000000000000001 :: Set new IP=10.15.254.205bindToController succesfullCurrent CGN=29502(2009-02-13 01:47:59) ~~.\cli\sraTestFailover.cpp:1332~~::TRIVIA::SMsra::TestFailover::createSnapshot::Snapshot creation succesfull.. Exit true(2009-02-13 01:47:59) ~~.\cli\sraTestFailover.cpp:424~~::VERBOSE::SMsra::TestFailover::toStart::createSnapshot returned, updating ObjectGraphbindToController succesfullCurrent CGN=29503(2009-02-13 01:47:59) ~~.\cli\sraTestFailover.cpp:429~~::VERBOSE::SMsra::TestFailover::toStart::Got new ObjectGraph, trying to validate the new Snapshot Volume(2009-02-13 01:47:59) ~~.\cli\sraTestFailover.cpp:1453~~::TRIVIA::SMsra::TestFailover::toStart::Snapshot Volume drsra-snap-0 exists(2009-02-13 01:47:59) ~~.\cli\sraTestFailover.cpp:1454~~::TRIVIA::SMsra::TestFailover::toStart::Snapshot Volume Status:1(2009-02-13 01:47:59) ~~.\cli\sraTestFailover.cpp:1455~~::TRIVIA::SMsra::TestFailover::toStart::Snapshot Volume Action:1(2009-02-13 01:47:59) ~~.\cli\sraTestFailover.cpp:1456~~::TRIVIA::SMsra::TestFailover::toStart::Base Volume Status:1(2009-02-13 01:47:59) ~~.\cli\sraTestFailover.cpp:1457~~::TRIVIA::SMsra::TestFailover::toStart::Base Volume Status:1(2009-02-13 01:47:59) ~~.\cli\sraTestFailover.cpp:433~~::TRIVIA::SMsra::TestFailover::toStart::Snapshot Volume exists(2009-02-13 01:47:59) ~~.\cli\sraTestFailover.cpp:447~~::VERBOSE::SMsra::TestFailover::toStart::Found snapshot volume just created(2009-02-13 01:47:59) ~~.\cli\sraTestFailover.cpp:455~~::TRIVIA::SMsra::TestFailover::toStart::Found a mapping for Base Volume(2009-02-13 01:47:59) ~~.\cli\sraTestFailover.cpp:464~~::VERBOSE::SMsra::TestFailover::toStart::Trying to create a mapping with Base Volume Initiator/InitiatorGroupbindToController succesfullCurrent CGN=29503(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 0(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 1(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 3(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 12(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 2(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 4(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 5(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 6(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 7(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 8(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 9(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 10(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 11(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 111(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 108(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 109(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 107(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 101(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 103(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 102(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 100(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 106(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 105(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 110(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 104(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:1654~~::INFO::SMsra::Returning LunNumber as 13(2009-02-13 01:48:00) ~~.\cli\sraTestFailover.cpp:472~~::VERBOSE::SMsra::TestFailover::toStart::New Lun Number generated is 13bindToController succesfullCurrent CGN=29503(2009-02-13 01:48:01) ~~.\cli\sraTestFailover.cpp:487~~::INFO::SMsra::TestFailover::toStart::Created a LUNMapping between snapshotVolume and Base Volume I/IG(2009-02-13 01:48:01) ~~.\cli\sraTestFailover.cpp:491~~::VERBOSE::SMsra::TestFailover::toStart::Done creating Mapping with base volume I/IG, checking LunAccess(2009-02-13 01:48:01) ~~.\cli\sraTestFailover.cpp:503~~::VERBOSE::SMsra::TestFailover::toStart::Checking if ReplicaLunKey 600a0b80004752200000f1884979823b matches the base Volume WWN(2009-02-13 01:48:01) ~~.\cli\sraTestFailover.cpp:503~~::VERBOSE::SMsra::TestFailover::toStart::Checking if ReplicaLunKey 600a0b80004771f40000f19a49797e87 matches the base Volume WWN(2009-02-13 01:48:01) ~~.\cli\sraTestFailover.cpp:513~~::VERBOSE::SMsra::TestFailover::toStart::Get the initiatorGroup object based on the Id(2009-02-13 01:48:01) ~~.\cli\sraTestFailover.cpp:1379~~::TRIVIA::SMsra::TestFailover::getInitiatorGroupWithId::Entry with initiatorGroupId=iScsi-fc-all(2009-02-13 01:48:01) ~~.\cli\sraTestFailover.cpp:1402~~::TRIVIA::SMsra::TestFailover::getInitiatorGroupWithId::Exit as false(2009-02-13 01:48:01) ~~.\cli\sraTestFailover.cpp:530~~::INFO::SMsra::TestFailover::toStart::Not found InitiatorGroup Object from ObjectBundle(2009-02-13 01:48:01) ~~.\cli\sraTestFailover.cpp:537~~::INFO::SMsra::TestFailover::toStart::Got InitiatorGroup from Command itself... Processing Initiator list(2009-02-13 01:48:01) ~~.\cli\sraTestFailover.cpp:1515~~::TRIVIA::SMsra::TestFailover::getInitiatorWithId::Entry with initId 2100001b321b9449(2009-02-13 01:48:01) ~~.\cli\sraTestFailover.cpp:1523~~::VERBOSE::SMsra::TestFailover::getInitiatorWithId::Got an initiator(2009-02-13 01:48:01) ~~.\cli\sraTestFailover.cpp:546~~::VERBOSE::SMsra::TestFailover::toStart::Preparing for createLUNMapping with Initiator object 2100001b321b9449...(2009-02-13 01:48:01) ~~.\cli\sraTestFailover.cpp:1343~~::TRIVIA::SMsra::TestFailover::createLunMapping::EntrybindToController succesfullCurrent CGN=29504(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1559~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::symRef is a Host(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1582~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Host associated to a CLUSTER(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 0(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 1(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 3(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 12(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 2(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 4(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 5(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 6(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 7(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 8(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 9(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 10(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 11(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 111(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 108(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 109(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 107(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 101(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 103(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 102(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 100(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 106(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 105(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 110(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 104(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 13(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1654~~::INFO::SMsra::Returning LunNumber as 14(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1349~~::VERBOSE::SMsra::TestFailover::createLunMapping::Got newLunNumber as 14bindToController succesfullCurrent CGN=29504(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1357~~::TRIVIA::SMsra::TestFailover::createLunMapping::createLunMapping returned(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1361~~::ERROR::SMsra::TestFailover::createLunMapping::Failover complete but create LUNMapping failed for with ReturnCode 63(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:553~~::VERBOSE::SMsra::TestFailover::toStart::createLunMapping failed, going to next initiatorId...(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1515~~::TRIVIA::SMsra::TestFailover::getInitiatorWithId::Entry with initId 2100001b321bea4a(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1523~~::VERBOSE::SMsra::TestFailover::getInitiatorWithId::Got an initiator(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:546~~::VERBOSE::SMsra::TestFailover::toStart::Preparing for createLUNMapping with Initiator object 2100001b321bea4a...(2009-02-13 01:48:02) ~~.\cli\sraTestFailover.cpp:1343~~::TRIVIA::SMsra::TestFailover::createLunMapping::EntrybindToController succesfullCurrent CGN=29504(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1559~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::symRef is a Host(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1582~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Host associated to a CLUSTER(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 0(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 1(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 3(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 12(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 2(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 4(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 5(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 6(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 7(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 8(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 9(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 10(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 11(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 111(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 108(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 109(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 107(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 101(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 103(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 102(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 100(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 106(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 105(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 110(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 104(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 13(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1654~~::INFO::SMsra::Returning LunNumber as 14(2009-02-13 01:48:03) ~~.\cli\sraTestFailover.cpp:1349~~::VERBOSE::SMsra::TestFailover::createLunMapping::Got newLunNumber as 14bindToController succesfullCurrent CGN=29504(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1357~~::TRIVIA::SMsra::TestFailover::createLunMapping::createLunMapping returned(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1361~~::ERROR::SMsra::TestFailover::createLunMapping::Failover complete but create LUNMapping failed for with ReturnCode 63(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:553~~::VERBOSE::SMsra::TestFailover::toStart::createLunMapping failed, going to next initiatorId...(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1515~~::TRIVIA::SMsra::TestFailover::getInitiatorWithId::Entry with initId 2100001b321b4649(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1523~~::VERBOSE::SMsra::TestFailover::getInitiatorWithId::Got an initiator(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:546~~::VERBOSE::SMsra::TestFailover::toStart::Preparing for createLUNMapping with Initiator object 2100001b321b4649...(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1343~~::TRIVIA::SMsra::TestFailover::createLunMapping::EntrybindToController succesfullCurrent CGN=29504(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1559~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::symRef is a Host(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1582~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Host associated to a CLUSTER(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 0(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 1(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 3(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 12(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 2(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 4(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 5(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 6(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 7(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 8(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 9(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 10(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 11(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 111(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 108(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 109(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 107(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 101(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 103(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 102(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 100(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 106(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 105(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 110(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 104(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 13(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1654~~::INFO::SMsra::Returning LunNumber as 14(2009-02-13 01:48:04) ~~.\cli\sraTestFailover.cpp:1349~~::VERBOSE::SMsra::TestFailover::createLunMapping::Got newLunNumber as 14bindToController succesfullCurrent CGN=29504(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1357~~::TRIVIA::SMsra::TestFailover::createLunMapping::createLunMapping returned(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1361~~::ERROR::SMsra::TestFailover::createLunMapping::Failover complete but create LUNMapping failed for with ReturnCode 63(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:553~~::VERBOSE::SMsra::TestFailover::toStart::createLunMapping failed, going to next initiatorId...(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1515~~::TRIVIA::SMsra::TestFailover::getInitiatorWithId::Entry with initId 2100001b321ad3d5(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1523~~::VERBOSE::SMsra::TestFailover::getInitiatorWithId::Got an initiator(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:546~~::VERBOSE::SMsra::TestFailover::toStart::Preparing for createLUNMapping with Initiator object 2100001b321ad3d5...(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1343~~::TRIVIA::SMsra::TestFailover::createLunMapping::EntrybindToController succesfullCurrent CGN=29504(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1559~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::symRef is a Host(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1582~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Host associated to a CLUSTER(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 0(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 1(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 3(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 12(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 2(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 4(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 5(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 6(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 7(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 8(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 9(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 10(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 11(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 111(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 108(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 109(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 107(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 101(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 103(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 102(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 100(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 106(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 105(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 110(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 104(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 13(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1654~~::INFO::SMsra::Returning LunNumber as 14(2009-02-13 01:48:05) ~~.\cli\sraTestFailover.cpp:1349~~::VERBOSE::SMsra::TestFailover::createLunMapping::Got newLunNumber as 14bindToController succesfullCurrent CGN=29504(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1357~~::TRIVIA::SMsra::TestFailover::createLunMapping::createLunMapping returned(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1361~~::ERROR::SMsra::TestFailover::createLunMapping::Failover complete but create LUNMapping failed for with ReturnCode 63(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:553~~::VERBOSE::SMsra::TestFailover::toStart::createLunMapping failed, going to next initiatorId...(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:503~~::VERBOSE::SMsra::TestFailover::toStart::Checking if ReplicaLunKey 600a0b80004752200000f1884979823b matches the base Volume WWN(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:503~~::VERBOSE::SMsra::TestFailover::toStart::Checking if ReplicaLunKey 600a0b80004771f40000f19a49797e87 matches the base Volume WWN(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:513~~::VERBOSE::SMsra::TestFailover::toStart::Get the initiatorGroup object based on the Id(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1379~~::TRIVIA::SMsra::TestFailover::getInitiatorGroupWithId::Entry with initiatorGroupId=iScsi-fc-all(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1402~~::TRIVIA::SMsra::TestFailover::getInitiatorGroupWithId::Exit as false(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:530~~::INFO::SMsra::TestFailover::toStart::Not found InitiatorGroup Object from ObjectBundle(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:537~~::INFO::SMsra::TestFailover::toStart::Got InitiatorGroup from Command itself... Processing Initiator list(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1515~~::TRIVIA::SMsra::TestFailover::getInitiatorWithId::Entry with initId 2100001b321b9449(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1523~~::VERBOSE::SMsra::TestFailover::getInitiatorWithId::Got an initiator(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:546~~::VERBOSE::SMsra::TestFailover::toStart::Preparing for createLUNMapping with Initiator object 2100001b321b9449...(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1343~~::TRIVIA::SMsra::TestFailover::createLunMapping::EntrybindToController succesfullCurrent CGN=29504(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1559~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::symRef is a Host(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1582~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Host associated to a CLUSTER(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 0(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 1(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 3(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 12(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 2(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 4(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 5(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 6(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 7(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 8(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 9(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 10(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 11(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 111(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 108(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 109(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 107(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 101(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 103(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 102(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 100(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 106(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 105(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 110(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 104(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 13(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1654~~::INFO::SMsra::Returning LunNumber as 14(2009-02-13 01:48:06) ~~.\cli\sraTestFailover.cpp:1349~~::VERBOSE::SMsra::TestFailover::createLunMapping::Got newLunNumber as 14bindToController succesfullCurrent CGN=29504(2009-02-13 01:48:07) ~~.\cli\sraTestFailover.cpp:1357~~::TRIVIA::SMsra::TestFailover::createLunMapping::createLunMapping returned(2009-02-13 01:48:07) ~~.\cli\sraTestFailover.cpp:1361~~::ERROR::SMsra::TestFailover::createLunMapping::Failover complete but create LUNMapping failed for with ReturnCode 63(2009-02-13 01:48:07) ~~.\cli\sraTestFailover.cpp:553~~::VERBOSE::SMsra::TestFailover::toStart::createLunMapping failed, going to next initiatorId...(2009-02-13 01:48:07) ~~.\cli\sraTestFailover.cpp:1515~~::TRIVIA::SMsra::TestFailover::getInitiatorWithId::Entry with initId 2100001b321bea4a(2009-02-13 01:48:07) ~~.\cli\sraTestFailover.cpp:1523~~::VERBOSE::SMsra::TestFailover::getInitiatorWithId::Got an initiator(2009-02-13 01:48:07) ~~.\cli\sraTestFailover.cpp:546~~::VERBOSE::SMsra::TestFailover::toStart::Preparing for createLUNMapping with Initiator object 2100001b321bea4a...(2009-02-13 01:48:07) ~~.\cli\sraTestFailover.cpp:1343~~::TRIVIA::SMsra::TestFailover::createLunMapping::EntrybindToController succesfullCurrent CGN=29504(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1559~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::symRef is a Host(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1582~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Host associated to a CLUSTER(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 0(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 1(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 3(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 12(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 2(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 4(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 5(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 6(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 7(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 8(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 9(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 10(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 11(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 111(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 108(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 109(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 107(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 101(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 103(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 102(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 100(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 106(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 105(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 110(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 104(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 13(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1654~~::INFO::SMsra::Returning LunNumber as 14(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1349~~::VERBOSE::SMsra::TestFailover::createLunMapping::Got newLunNumber as 14bindToController succesfullCurrent CGN=29504(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1357~~::TRIVIA::SMsra::TestFailover::createLunMapping::createLunMapping returned(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1361~~::ERROR::SMsra::TestFailover::createLunMapping::Failover complete but create LUNMapping failed for with ReturnCode 63(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:553~~::VERBOSE::SMsra::TestFailover::toStart::createLunMapping failed, going to next initiatorId...(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1515~~::TRIVIA::SMsra::TestFailover::getInitiatorWithId::Entry with initId 2100001b321b4649(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1523~~::VERBOSE::SMsra::TestFailover::getInitiatorWithId::Got an initiator(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:546~~::VERBOSE::SMsra::TestFailover::toStart::Preparing for createLUNMapping with Initiator object 2100001b321b4649...(2009-02-13 01:48:08) ~~.\cli\sraTestFailover.cpp:1343~~::TRIVIA::SMsra::TestFailover::createLunMapping::EntrybindToController succesfullCurrent CGN=29504(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1559~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::symRef is a Host(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1582~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Host associated to a CLUSTER(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 0(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 1(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 3(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 12(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 2(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 4(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 5(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 6(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 7(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 8(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 9(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 10(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 11(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 111(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 108(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 109(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 107(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 101(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 103(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 102(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 100(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 106(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 105(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 110(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 104(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 13(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1654~~::INFO::SMsra::Returning LunNumber as 14(2009-02-13 01:48:09) ~~.\cli\sraTestFailover.cpp:1349~~::VERBOSE::SMsra::TestFailover::createLunMapping::Got newLunNumber as 14bindToController succesfullCurrent CGN=29504(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1357~~::TRIVIA::SMsra::TestFailover::createLunMapping::createLunMapping returned(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1361~~::ERROR::SMsra::TestFailover::createLunMapping::Failover complete but create LUNMapping failed for with ReturnCode 63(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:553~~::VERBOSE::SMsra::TestFailover::toStart::createLunMapping failed, going to next initiatorId...(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1515~~::TRIVIA::SMsra::TestFailover::getInitiatorWithId::Entry with initId 2100001b321ad3d5(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1523~~::VERBOSE::SMsra::TestFailover::getInitiatorWithId::Got an initiator(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:546~~::VERBOSE::SMsra::TestFailover::toStart::Preparing for createLUNMapping with Initiator object 2100001b321ad3d5...(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1343~~::TRIVIA::SMsra::TestFailover::createLunMapping::EntrybindToController succesfullCurrent CGN=29504(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1559~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::symRef is a Host(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1582~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Host associated to a CLUSTER(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 0(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 1(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 3(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 12(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 2(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 4(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 5(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 6(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 7(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 8(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 9(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 10(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 11(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 111(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 108(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 109(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 107(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 101(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 103(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 102(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 100(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 106(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 105(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 110(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 104(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1605~~::TRIVIA::SMsra::TestFailover::getNewLunNumber::Cluster->LUN 13(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1654~~::INFO::SMsra::Returning LunNumber as 14(2009-02-13 01:48:10) ~~.\cli\sraTestFailover.cpp:1349~~::VERBOSE::SMsra::TestFailover::createLunMapping::Got newLunNumber as 14bindToController succesfullCurrent CGN=29504(2009-02-13 01:48:11) ~~.\cli\sraTestFailover.cpp:1357~~::TRIVIA::SMsra::TestFailover::createLunMapping::createLunMapping returned(2009-02-13 01:48:11) ~~.\cli\sraTestFailover.cpp:1361~~::ERROR::SMsra::TestFailover::createLunMapping::Failover complete but create LUNMapping failed for with ReturnCode 63(2009-02-13 01:48:11) ~~.\cli\sraTestFailover.cpp:553~~::VERBOSE::SMsra::TestFailover::toStart::createLunMapping failed, going to next initiatorId...(2009-02-13 01:48:11) ~~.\cli\sraTestFailover.cpp:1170~~::VERBOSE::SMsra::TestFailover::getVolumeWithWWN::Got Volume with WWN 600a0b80004752200000f1884979823b(2009-02-13 01:48:11) ~~.\cli\sraTestFailover.cpp:386~~::VERBOSE::SMsra::TestFailover::toStart::Got Volume(2009-02-13 01:48:11) ~~.\cli\sraTestFailover.cpp:401~~::VERBOSE::SMsra::TestFailover::toStart::Volume status is Optimal(2009-02-13 01:48:11) ~~.\cli\sraTestFailover.cpp:411~~::VERBOSE::SMsra::TestFailover::toStart::Snapshot for Volume not present, Creating Snapshot(2009-02-13 01:48:11) ~~.\cli\sraTestFailover.cpp:1507~~::VERBOSE::SMsra::Next Snapshot Count=1bindToController succesfullCurrent CGN=295042009-02-13:: 13:48:20:INFO:main:Done with failover Error: .

www.ivobeerens.nl

Re: DS4000 SRM issues

mariab — Thu, 19 Feb 2009 15:43:11 GMT

Could you post SRM logs from the recovery site?

-Masha

Re: DS4000 SRM issues

iefke — Thu, 19 Feb 2009 15:41:26 GMT

when i run i recovery plan with one vm with one disk everything is okay. When i run the recovery plan with a vm with two or more disks (one two of more luns) the test recovery fails on the prepare strorage.

www.ivobeerens.nl

Re: DS4000 SRM issues

mariab — Thu, 19 Feb 2009 15:17:57 GMT

i've got a new SRA (it's not on the VMware site) from IBM that solves the SRA problem but introduces another.

Could you provide detail about the new problem?

-Masha

Re: DS4000 SRM issues

iefke — Thu, 19 Feb 2009 14:59:58 GMT

i've got a new SRA (it's not on the VMware site) from IBM that solves the SRA problem but introduces another.

www.ivobeerens.nl

Re: DS4000 SRM issues

dex_1234 — Thu, 12 Feb 2009 19:58:29 GMT

There will be a new IBM SRA build out shorly that should resolve this error. Upgrade the SRA at both sites once it releases. I'll check to see how soon.

Re: DS4000 SRM issues

iefke — Thu, 12 Feb 2009 19:39:31 GMT

Config: 2 x IBM DS 5100 firmware 07.36.12.00, synchrone replication
VMware ESX 3.5 U3 including all January 2009 updates
VMware SRM version 1.0.1 build 128004

Problem: We have problems with configuring the SRA. The first problem was the following error during the first screen in the SRA
LUN's with duplicate IDs or numbers..................
We had the following config:
host a lun a mapped with lun id 0 (vmware cluster)
host b lun b mappeld with lun id 0 (Windows cluster host)
I changed all the LUN id with unique numbers. Now the error went away,

The following problem is that the SRA does not see replicated datastores in the last screen in the SRA. The LUNs are all in sync and replicated.
In the SRM logs i found the following errors:
~~2009-02-12 15:49:25.084 'SanConfigManager' 4144 verbose~~ Recomputing LUN groups for array pair '600a0b80004771f400000000493389ff' --> '600a0b80004770680000000049364b17'
~~2009-02-12 15:49:25.084 'SanConfigManager' 4144 verbose~~ Found 20 replicated LUN pairs
~~2009-02-12 15:49:25.084 'SanConfigManager' 4144 verbose~~ No lun groups created since there are no replicated datastores

Has anybody a suggestion for this problem?

www.ivobeerens.nl

Re: DS4000 SRM issues

Iuridae — Tue, 27 Jan 2009 15:20:52 GMT

Yes, thats correct. When we made some disk unconfigured the error disappeared.

For the snapshot to work there need to be free disks thats isn't a part of a raid-set.

Re: DS4000 SRM issues

KrishnaR — Tue, 27 Jan 2009 15:18:11 GMT

This message indicates that you've run out of free disks during the testFailover process. See note on restriction in 01.00.35.07 Readme. This restriction will be lifted in an upcoming SRA release.

Re: DS4000 SRM issues

mariab — Tue, 27 Jan 2009 13:00:31 GMT

"Message exceeds database maximum string length." error is harmless. However, it might indicate that storage operation failed. Details about storage failure are in the SRM logs. Could you post these logs from recovery site?

-Masha

Re: DS4000 SRM issues

Iuridae — Tue, 27 Jan 2009 08:31:29 GMT

1 bindToController succesfull
1 Current CGN=508
1 2009-01-20:: 16:41:35:INFO:main:Done with failover
1
1 Error:
1
1 ",
1 msg = "Message exceeds database maximum string length."
1 }
1] ,
1 msg = "Message exceeds database maximum string length."
1 }

We have been struggling with that error and haven't found a solution to it. First impression is that some column in SRM datastore is to short.
We are running SRM 1.0 update 1 and SRA 1.00.35.07 and recieves that error when we run a test failover.

Any help would be appreciated.

Re: DS4000 SRM issues

Sarek — Mon, 05 Jan 2009 10:47:56 GMT

Iuridae wrote:
Hi Dex,

I assume that the read-only LUNs will be added once a test failover/failover will occure?
Yes these LUNs will be seen when the failover is completed.

If you find this information useful, please award points for "correct" or "helpful".

Re: DS4000 SRM issues

Iuridae — Fri, 02 Jan 2009 07:28:50 GMT

Hi Dex,

As I understand most of it has been done, except enabled flashcopy on the the storages.The communication works and also mirroring. On each site the ESX hosts can see both the Primary LUNs and the mirrored Secondary read-only LUNs, however only the Primary LUNs have been added as ESX storage. I assume that the read-only LUNs will be added once a test failover/failover will occure?

Very informative post, very helpful! Thank you!

Re: DS4000 SRM issues

dex_1234 — Wed, 31 Dec 2008 06:19:37 GMT

From the storage configuration perspective, you'll want to ensure you have flashcopy and ERM enable on both the protected and recovery site DS4700 subsystems.( assuming you want to test failback in both directions or at least have flashcopy enabled on the recovery side subsystem) You'll want to go ahead and activate ERM and configure the logical drives that you want to mirror with StorageManager for the protected site subsystem to the recovery site subsystem.( I'm assuming the physical communication for the subystems has already been configured, if you're working within a local test configuration, go ahead and make sure you have have the two subsytems communicating via a fabric through its mirroring ports ). You'll want the mirroring relationship established before proceeding with the rest of SRM configuration. The logical drives that are in the mirror relationship at the recovery side should already be mapped as well. This is probably a good time to point out that you want to have your mapping and partitioning layout configured via StorageManger for the protected/recovery side subsytems. I went ahead and manually scanned for all of the LUNs that I expected to be registered by the recovery side ESX hosts to make sure all LUNs were correctly seen and also that my multipathing design worked as I intended in regards to the number of paths available to my recovery side subsystem. The multipath considerations is often overlooked so make sure you see the LUNs as expected, number of paths as expected and so forth. DS4000/5000 multipathing behavior under the current VMware failover code probrably deserves its own thread, but multipathing design is a critical consideraton of your BC/DR planning with SRM and DS4/5K line subsystems. Once you get furthur into SRM configuration, it'll become more clear as to what SRM sees from it's perspective. The reason you need flashcopy enabled on the subsystem is if you run a test of your recovery plan later. The SRM server on the recovery side via its SRA adapter will initiate a flashcopy of your mirrored logical drives and it's the flashcopy that is presented to the recovery side ESX servers. Note that the recovery side logical drives in the mirror relationship is read only until they are promoted, but during the testing of your recovery plan you want a READ/WRITABLE logical drive for ESX to register. In short, configure mirroring, mapping/partition layout, and multipathing design as desired for the DS4700 first then proceed with the rest of SRM/SRA pre and post configuration. If you administer both the ESX and storage layers then its straight forward, but if you're in a large enterprise with a different storage group and possibly SAN/NETWORK group, you'll want to coordinate with these guys as well. Just from my own personal insight, the lack of communication can really cause problems in the design of your SRM strategy. Hope some of this helps.

Re: DS4000 SRM issues

Iuridae — Mon, 29 Dec 2008 16:02:31 GMT

Hi everyone!

Just the thread for me. We're about to setup the recovery plans and have a few questions about what to expect next time we return to our datacenter.

We have four hosts diveded into two sites with a DS4700 Storage on each site. We want it to be bi-directional. So far we have installed ESX 3.5 U3, VC 2.5 U3 and SRM 1.0 (not U1) and the IBM Array Manager. We managed to see the LUN ID in the Array Manager after we added the path to the pearl folder to the enviroment varaible and things seems to work. This is how we left it and will return in short.

But, each host can only see the Primary LUN on their DS4700. Do they need to see the secondary LUN mirrored from the other site, or how does this part work? Activate FlashCopy i read before. Is this a necessary step and is there more we should think about?

Thanks in advance,

Re: DS4000 SRM issues

KrishnaR — Fri, 07 Nov 2008 20:22:00 GMT

And yes, SRM 1.0 only supports ESX 3.5U1 (and VC 2.5U1).

Re: DS4000 SRM issues

KrishnaR — Fri, 07 Nov 2008 20:15:47 GMT

Bob is correct. 06.60.xx.xx is unsupported SP FW. The API used for the SRA is not fully compatible with this older FW. So the SRA COULD work with 06.60 but it's not guaranteed to.

Sarek, the scripts path is registered when SRA is installed. There was some question as to whether SRM should the one the register Perl. We're resolving that now and it should be fixed for the next SRM/SRA release. Until then, unfortunately, the Perl path has to be added manually to the Windows PATH variable.

Re: DS4000 SRM issues

rwmiller — Fri, 07 Nov 2008 09:39:02 GMT

Hello,

Your firmware is down level and will not work with the SRA. One thing that can be confusing is that there are two different version numbers used with the IBM DS. One is for their management software which will be version 10.10.xx.xx and the other is for the firmware in the array which would be 7.10.xx.xx. You indicate that your array is running version 6.60.xx.xx firmware and that is downlevel from the 7.10.xx.xx release and in fact the 7.10 release was a major upgrade in the firmware with a lot of enchancements and changes such as removing the 2TB volume size limit. The upgraded firmware is avaliable but be aware that you have to take the array offline to do this upgrade unlike other previous upgrades and that if you do upgrade you can not go back without having to restore your data from backup.

Bob

Re: DS4000 SRM issues

Sarek — Mon, 03 Nov 2008 14:10:59 GMT

Added the following path: "D:\VMware\VMware Site Recovery Manager\external\perl-5.8.8\bin";"D:\VMware\VMware Site Recovery Manager\scripts\SAN\IBM" to the environment variables. And now i can add the storage (local en remote).

Shouldn't these paths be added with the install of VMware SRM on the server ??

Sarek

Re: DS4000 SRM issues

Sarek — Mon, 03 Nov 2008 08:52:47 GMT

I'm in the process of installing SRM on a DS4800 (1 on each site). I have got the hotfix for Update 1, and it states:

*The
VMkernel build number MUST BE equal to 82663, otherwise, the hot patch cannot
be installed*

my output is:
~~root@dzmesx005 root~~# rpm -qa | grep vmkernel
VMware-esx-vmkernel-3.5.0-113339

This means i can't install the patch at the moment, or i'll have to downgrade all my ESX server to Update 1 (build 82663).

The problem i have is that the array manager gives the error message: ERROR OCCURED.

When i look at the logging i see the following error (highlighted the section with the error)

~~2008-10-31 14:19:51.387 'PrimarySanProvider' 2300 info~~ Command Line for discoverArrays: "D:\VMware\VMware Site Recovery Manager\external\perl-5.8.8\bin\perl.exe" "D:/VMware/VMware Site Recovery Manager/scripts/SAN/IBM/command.pl"
~~2008-10-31 14:19:51.387 'PrimarySanProvider' 2300 verbose~~ Input for discoverArrays: <?xml version="1.0" encoding="UTF-8"?>
1 <Command>
1 <Name>discoverArrays</Name>
1 <ConnectSpec>
1 <Name>DS4800</Name>
1 <Address>225.255.255.255</Address>
1 <Address>225.255.255.255</Address>
1 </ConnectSpec>
1 <OutputFile>C:\WINDOWS\TEMP\vmware-SYSTEM\dr-sanprovider0</OutputFile>
1 <LogLevel>trivia</LogLevel>
1 </Command>
~~2008-10-31 14:19:51.387 'PrimarySanProvider' 2300 trivia~~ Environment ALLUSERSPROFILE=C:\Documents and Settings\All Users will be set for the script
~~2008-10-31 14:19:51.387 'PrimarySanProvider' 2300 trivia~~ Environment ClusterLog=C:\WINDOWS\Cluster\cluster.log will be set for the script
~~2008-10-31 14:19:51.387 'PrimarySanProvider' 2300 trivia~~ Environment CommonProgramFiles=C:\Program Files\Common Files will be set for the script
~~2008-10-31 14:19:51.387 'PrimarySanProvider' 2300 trivia~~ Environment COMPUTERNAME=DZMVC001 will be set for the script
~~2008-10-31 14:19:51.387 'PrimarySanProvider' 2300 trivia~~ Environment ComSpec=C:\WINDOWS\system32\cmd.exe will be set for the script
~~2008-10-31 14:19:51.387 'PrimarySanProvider' 2300 trivia~~ Environment FP_NO_HOST_CHECK=NO will be set for the script
~~2008-10-31 14:19:51.387 'PrimarySanProvider' 2300 trivia~~ Environment NUMBER_OF_PROCESSORS=1 will be set for the script
~~2008-10-31 14:19:51.387 'PrimarySanProvider' 2300 trivia~~ Environment OS=Windows_NT will be set for the script
~~2008-10-31 14:19:51.387 'PrimarySanProvider' 2300 trivia~~ Environment Path=C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;D:\VMware\VMware Site Recovery Manager\scripts\SAN\IBM will be set for the script
~~2008-10-31 14:19:51.387 'PrimarySanProvider' 2300 trivia~~ Environment PATHEXT=.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH will be set for the script
~~2008-10-31 14:19:51.387 'PrimarySanProvider' 2300 trivia~~ Environment PROCESSOR_ARCHITECTURE=x86 will be set for the script
~~2008-10-31 14:19:51.387 'PrimarySanProvider' 2300 trivia~~ Environment PROCESSOR_IDENTIFIER=x86 Family 15 Model 4 Stepping 8, GenuineIntel will be set for the script
~~2008-10-31 14:19:51.387 'PrimarySanProvider' 2300 trivia~~ Environment PROCESSOR_LEVEL=15 will be set for the script
~~2008-10-31 14:19:51.387 'PrimarySanProvider' 2300 trivia~~ Environment PROCESSOR_REVISION=0408 will be set for the script
~~2008-10-31 14:19:51.387 'PrimarySanProvider' 2300 trivia~~ Environment ProgramFiles=C:\Program Files will be set for the script
~~2008-10-31 14:19:51.387 'PrimarySanProvider' 2300 trivia~~ Environment SystemDrive=C: will be set for the script
~~2008-10-31 14:19:51.387 'PrimarySanProvider' 2300 trivia~~ Environment SystemRoot=C:\WINDOWS will be set for the script
~~2008-10-31 14:19:51.387 'PrimarySanProvider' 2300 trivia~~ Environment TEMP=C:\WINDOWS\TEMP will be set for the script
~~2008-10-31 14:19:51.387 'PrimarySanProvider' 2300 trivia~~ Environment TMP=C:\WINDOWS\TEMP will be set for the script
~~2008-10-31 14:19:51.387 'PrimarySanProvider' 2300 trivia~~ Environment USERPROFILE=C:\Documents and Settings\Default User will be set for the script
~~2008-10-31 14:19:51.387 'PrimarySanProvider' 2300 trivia~~ Environment windir=C:\WINDOWS will be set for the script
~~2008-10-31 14:19:51.387 'SysCommandLineWin32' 2300 verbose~~ Starting process: "D:\\VMware
VMware Site Recovery Manager\\external\\perl-5.8.8\\bin
perl.exe" "D:/VMware/VMware Site Recovery Manager/scripts/SAN/IBM/command.pl"
~~2008-10-31 14:19:51.606 'PrimarySanProvider' 2300 info~~ discoverArrays exited with exit code 0
~~2008-10-31 14:19:51.606 'PrimarySanProvider' 2300 trivia~~ discoverArrays's output:
D:/VMware/VMware Site Recovery Manager/scripts/SAN/IBM2008-10-31:: 14:19:51:INFO:discoverArray:call the discoverArray.pl file.....
1 2008-10-31:: 14:19:51:INFO:discoverArray:exit discoverArrays.....

~~2008-10-31 14:19:51.606 'PrimarySanProvider' 2300 error~~ discoverArrays's errors:
'perl' is not recognized as an internal or external command,
1 operable program or batch file.

~~2008-10-31 14:19:51.606 'PrimarySanProvider' 2300 trivia~~ 'discoverArrays' returned
~~2008-10-31 14:19:51.606 'PrimarySanProvider' 2300 error~~ Failed to retrieve script results
~~2008-10-31 14:19:51.606 'ArrayManagerImpl.QueryInfoTask-Task' 2300 info~~ Work function threw std::exception: XML document is empty
~~2008-10-31 14:19:51.606 'ArrayManagerImpl.QueryInfoTask-Task' 2300 info~~ Fault:
(dr.fault.InternalError) {
1 dynamicType = <unset>,
1 reason = "XML document is empty",
1 msg = ""
1 }
~~2008-10-31 14:19:51.606 'ArrayManagerImpl.QueryInfoTask-Task' 2300 verbose~~ Error set to (dr.fault.InternalError) {
1 dynamicType = <unset>,
1 reason = "XML document is empty",
1 msg = ""
1 }

Has anyone have the same issue's, and is the solution downgrading to ESX 3.5 update 1 ?

Thx

Sarek

Re: DS4000 SRM issues

KrishnaR — Fri, 31 Oct 2008 22:30:41 GMT

Update - there is an ESX hotfix available for IBM SRA running on ESX 3.5U1 with SRM 1.0. This fix is already incorporated in U3 to support the next version of SRM.

Re: DS4000 SRM issues

KrishnaR — Wed, 15 Oct 2008 02:50:53 GMT

Another possible way to pursue support question is through IBM's RPQ process.

Re: DS4000 SRM issues

KrishnaR — Tue, 14 Oct 2008 05:58:29 GMT

SRM is only supported with 07.10+. No testing has been done with previous versions. I think it would take code changes to accomodate the previous FW's API.

Re: DS4000 SRM issues

mariab — Mon, 13 Oct 2008 13:31:03 GMT

Hi Brett,

I have a DS4800 and the matrix lists the following as the level

required. Does any one know if this is the minimum or supported version
levels?

Safe assumption would be that only the exact versions are supported. However, in most cases all higher versions are supported as well. It would be best to consult the vendor of the SRA about your particular version.

-Masha

Re: DS4000 SRM issues

beb — Mon, 13 Oct 2008 01:37:55 GMT

I am not sure that this question relates directly to this post, but after reading this post it looks like there is a wealth of knowledge here.

I am new to SRM and I am going to be installing it soon. I have checked all the requirements and the http://www.vmware.com/pdf/srm_10_compat_matrix.pdf. All is looking good to go except for my Storage.

I have a DS4800 and the matrix lists the following as the level required. Does any one know if this is the minimum or supported version levels?

Storage Replication Adapter Compatibility List for IBM Arrays

Hardware Models Firmware IBM Storage Manager

DS4800 07.10 and 07.15 10.10 and 10.15

My current versions are,

Hardware Models Firmware IBM Storage Manager

DS4800 06.60.02.00 09.60.G5.04

Does any one know if my current version will work or not?

Does any one have a link to the IBM SRA documentaion that may supply this information?

This is my first post on the Vmware community, so please let me know if I am posting incorrectly.

Any advise or assistance is much appreciated.

Brett

Re: DS4000 SRM issues

mariab — Fri, 10 Oct 2008 17:25:55 GMT

Hi TMeissner,

This looks like an SRA problem during test failover. Looking at the SRA log it seems that the operation was successfull, however the response indicated an error.

<?xml version="1.0" encoding="UTF-8"?>
<Response>
<ReturnCode>4</ReturnCode>
</Response>

...

(2008-10-07 10:45:06) ~~.\cli\sraTestFailover.cpp:302~~::TRIVIA::SMsra::TestFailover::performOp::Calling tfoStart
(2008-10-07 10:45:06) ~~.\cli\sraTestFailover.cpp:355~~::TRIVIA::SMsra::TestFailover::toStart::Entry
(2008-10-07 10:45:06) ~~.\cli\sraTestFailover.cpp:1170~~::VERBOSE::SMsra::TestFailover::getVolumeWithWWN::Got Volume with WWN 600a0b800042359600000c5848ce720f
(2008-10-07 10:45:06) ~~.\cli\sraTestFailover.cpp:386~~::VERBOSE::SMsra::TestFailover::toStart::Got Volume
(2008-10-07 10:45:06) ~~.\cli\sraTestFailover.cpp:401~~::VERBOSE::SMsra::TestFailover::toStart::Volume status is Optimal
(2008-10-07 10:45:06) ~~.\cli\sraTestFailover.cpp:411~~::VERBOSE::SMsra::TestFailover::toStart::Snapshot for Volume not present, Creating Snapshot
(2008-10-07 10:45:06) ~~.\cli\sraTestFailover.cpp:1507~~::VERBOSE::SMsra::Next Snapshot Count=0
bindToController succesfull
Current CGN=4115
2008-10-07:: 10:45:12:INFO:failover:exit failover.....

-Masha

Re: DS4000 SRM issues

KrishnaR — Wed, 08 Oct 2008 23:00:36 GMT

I'll take a look at these logs. I'm also willing to setup a WebEx or Netmeeting to get a look at your environment. If you could email me, we can work something out.

Re: DS4000 SRM issues

TMeissner — Wed, 08 Oct 2008 21:47:12 GMT

Our flashcopy on the recovery side is working using the default feature code that limits us to two flashcopies. I am just working with a single test LUN. I guess I'm stuck with the generic error:

#1] 2008-10-07:: 10:45:12:INFO:failover:exit failover.....
1
1 Error:
1
1 ",
1 msg = "Message exceeds database maximum string length."
1 }
1] ,
1 msg = "Message exceeds database maximum string length."
1 }
~~2008-10-07 10:45:26.071 'Cancel-RecoveryContext-16-17-Task' 3848 verbose~~ Task destroyed

I've attached our log for the error. Any insight would be appreciated. If you think this is a bug in the SRA code ... that OK, just let me know. I'm getting tired of chasing this one. Is there any other information that would be helpful?

Re: DS4000 SRM issues

Mike_Laverick — Tue, 07 Oct 2008 20:06:18 GMT

Can I say what an interesting thread this has been/is....

A couple of observations:

1. An SRA which has a case-sensitive error in the perl script is a pretty bad show...

2. I don't recall seeing a SRA for the DS4000 being available in the download - perhaps I was observant enough.

3. I think some (not all) of the vendors have been a bit remiss in the documentation. It kind of reminds me of the early days of VCB. When we were very much left to own skills to resolve problems. Frequently the PDFs available assume very good knowledge of the storage - which is not very helpful to the average VMware guy who is not a storage expert. I'm quite happy to put myself in this camp - I don't like to exaggerate my knowledge on these forums!

I think what need is more "Getting Started with..." style documentation - written by people who are not pro-storage guys....

4. PDF guide to DS4000. I'm very close to releasing my book on SRM. I've hard copy on the way to me. As long as it looks ok, I will be releasing it on LULU. We can also use LULU to distribute free PDFs. If any one want to share what they have learned from this - I would be happy to host these PDFs on my LULU account. There's a cost for me to do this - but I'm happy to do this - as it's helpful to the community and a helpful free supplement to my book....

Regards
Mike

Re: DS4000 SRM issues

TMeissner — Tue, 07 Oct 2008 19:27:55 GMT

Item 2)

Using IBM DS4000/FastT Storage Manager, you can define Host Groups to quickly map the VMFS LUNS to a group of ESX servers at the same time. When a LUN is mapped to a Host group up can assign the LUN ID from 0 to xxx. If you map a LUN to an individual server you can also assign the LUN IS from 0 to xxx. The problem comes when the are identical LUN IDs used between a Host Group mapping and individual hosts. The Storage Manager application allows this and somehow can tell the difference between Host Group and an individual host. I think the SRA requests the host mappings and sees two mappings that use the same LUN IDs. It is not aware that one of those ID's is a part of a Host Group.

My workaround was to change the LUN Id's for the DS4700 to insure they were unique. After making the change we no longer received the Duplicate ID's error.

Thanks

Re: DS4000 SRM issues

KrishnaR — Tue, 07 Oct 2008 19:22:33 GMT

That's why I couldn't recreate - I'm running with DS4800. Looks like ReturnCode issue only pops up in a 4700 specific section. I'll update our database with that info. I'll wait to hear if 2) is a genuine issue after you've fixed FlashCopy.

Re: DS4000 SRM issues

TMeissner — Tue, 07 Oct 2008 19:00:13 GMT

Thanks for the response....

As for the "ReturnCode" error .... v1.00.35.03 of the SRA for the DS4700 has an error. In the command.pl and the command.pm files there is string value, $XML_RETURNCODE = "Returncode"; This needs to be changed to "ReturnCode" with a captial C. I made the change to the script and it fixed the XML error that I was getting. I am assuming that the SRA version will be updated on the VMware site.

Now my next error in the logs are that there is an invalid snapshot of the volume. I am assuming that this is really a flashcopy issue. We are working with IBM to get the proper Flashcopy feature code activation on the recovery side DS-4700.

Re: DS4000 SRM issues

KrishnaR — Tue, 07 Oct 2008 18:46:45 GMT

DS4000 does use FlashCopy to create a snapshot of the mirrored LUN. So yes, this needs to be enabled on the recovery side (on both sides if you're configuring bidirectional protection). I'd have to dig into dev docs to see what error code is returned but suffice it to say, without ability to create snapshots, SRM testFailover will fail. I'd like to see a retest after enabling FlashCopy. Still tracking 3 other issues -

1) ReturnCode error - Can't reproduce error. Does this go away when FlashCopy is enabled?

2) testFailover does not work if same LUN numbers are used on different hosts - Can I get further explanation on this?

3) DS4000 patch - I'm working with VMware to release a patch that affects DS4000 SRM. Will update thread when this is finalized.

Afaik, IBM does not have an SRM guide yet. I've made progress on my guide and should hopefully be ready to release it in the coming month.

Re: DS4000 SRM issues

Mike_Laverick — Mon, 06 Oct 2008 13:21:45 GMT

TMeissner wrote:

I attended a User Group Meeting where another storage vendor demonstrated SRM. In their presentation, they implied that during their testing, a "clone" was made of the LUN to be able to isolate the VMFS volume during the test and still keep the replication going. I was wondering if the SRA for the DS4000 is doing something like this. If so does that implied that the DS4000 on the recovery side needs to have a FlashCopy Feature Code? If so, what error would I see if the feature code is missing?

Thanks!!

I wouldn't be suprised. In my research most SRA do this - the only one which doesn't appear to make a snapshot "on-the-fly" is LHN (Adam is that right?!?!?). I'm not sure of the requirements for FlashCopy. What does the README or PDF file say there requirements are...???

Does IBM have redbook on SRA/SRM???

Regards
Mike

Re: DS4000 SRM issues

TMeissner — Fri, 03 Oct 2008 16:44:26 GMT

Thanks!!

Re: DS4000 SRM issues

TMeissner — Tue, 30 Sep 2008 17:45:14 GMT

Hi - thanks for starting this thread ...

Thru the sales channel you received an error log from our eval. We were getting the following error: "Error: Invalid XML returned from storage array management script: Failed to get node ReturnCode." Your response to our logs was ... "it looks like the LSI SRA is returning a misspelled element in its response to the testFailover/start command" You suggested P#8 would fix this issue. Currently, there is only one SRA for the DS4000 available for download. The version I am using is 1.00.35.03. Does this version of the SRA have the fix or should I be looking someplace else?

thanks!!

ToddM

I attempted to correct the problem by reloading SRM. I was not surprised to sse the same error. ... attached is my latest log file. Message was edited by: TMeissner