All,
I have a customer that is using SC 3.6 to create local snapshots and then register the snapshots with PM to perform SnapMirrors and SnapVaults. The Vault is working fine as the secondary is located in the same building. However, as for SnapMirror, Protection Manager is reporting that the SnapMirror Updates are failing (intermittently) and at the same time, from a filer perspective, the updates are completing successfully. It seems as if PM is not receiving API acknowledgement from the DR filer. What could be the reason for this?
Here is what the logs are showing:
SNAPCREATOR LOG
[Fri Jul 19 09:20:00 2013] INFO: Logfile timestamp: 20130719092000
[Fri Jul 19 09:20:00 2013] INFO: Removing log dfsupmvintp01_snap.out.20130718062000.log
[Fri Jul 19 09:20:00 2013] INFO: Removing log dfsupmvintp01_snap.debug.20130718062000.log
[Fri Jul 19 09:20:00 2013] INFO: Removing log dfsupmvintp01_snap.stderr.20130718062000.log
########## Parsing Environment Parameters ##########
########## PRE APPLICATION QUIESCE COMMANDS ##########
[Fri Jul 19 09:20:00 2013] INFO: No commands defined
########## PRE APPLICATION QUIESCE COMMANDS FINISHED SUCCESSFULLY ##########
########## APPLICATION QUIESCE COMMANDS ##########
[Fri Jul 19 09:20:00 2013] INFO: No commands defined
########## APPLICATION QUIESCE COMMANDS FINISHED SUCCESSFULLY ##########
########## POST APPLICATION QUIESCE COMMANDS ##########
[Fri Jul 19 09:20:00 2013] INFO: No commands defined
########## POST APPLICATION QUIESCE COMMANDS FINISHED SUCCESSFULLY ##########
########## PRE COMMANDS ##########
[Fri Jul 19 09:20:00 2013] INFO: No commands defined
########## PRE COMMANDS FINISHED SUCCESSFULLY ##########
########## Parsing Environment Parameters ##########
[Fri Jul 19 09:20:00 2013] WARN: Snapshot's will not be deleted, if this is not desired please set NTAP_SNAPSHOT_NODELETE=N in config file
########## Detecting Data OnTap mode for netapp2 ##########
[Fri Jul 19 09:20:03 2013] INFO: Data OnTap 7 mode detected
########## Generating Info ASUP on netapp2 ##########
[Fri Jul 19 09:20:03 2013] INFO: ASUP create on netapp2 finished successfully
########## Gathering Information for netapp2:FileServer_vol11 ##########
[Fri Jul 19 09:20:03 2013] INFO: Performing Snapshot Inventory for FileServer_vol11 on netapp2
[Fri Jul 19 09:20:03 2013] INFO: Snapshot Inventory of FileServer_vol11 on netapp2 completed Successfully
########## Running Snapshot Rename on Primary netapp2 ##########
########## Creating snapshot(s) ##########
########## SNAPSHOT CREATE COMMANDS ##########
[Fri Jul 19 09:20:03 2013] INFO: Running snapshot create command NTAP_SNAPSHOT_CREATE_CMD01 ["c:/Program Files/NetApp/SnapDrive/sdcli" snap create -s dfsupmvintp01-hourly_20130719092000 -D U]
[Fri Jul 19 09:21:04 2013] INFO: Running snapshot create command ["c:/Program Files/NetApp/SnapDrive/sdcli" snap create -s dfsupmvintp01-hourly_20130719092000 -D U] finished successfully
########## SNAPSHOT CREATE COMMANDS FINISHED SUCCESSFULLY ##########
########## PRE APPLICATION UNQUIESCE COMMANDS ##########
[Fri Jul 19 09:21:04 2013] INFO: No commands defined
########## PRE APPLICATION UNQUIESCE COMMANDS FINISHED SUCCESSFULLY ##########
########## APPLICATION UNQUIESCE COMMANDS ##########
[Fri Jul 19 09:21:04 2013] INFO: No commands defined
########## APPLICATION UNQUIESCE COMMANDS FINISHED SUCCESSFULLY ##########
########## POST APPLICATION UNQUIESCE COMMANDS ##########
[Fri Jul 19 09:21:04 2013] INFO: No commands defined
########## POST APPLICATION UNQUIESCE COMMANDS FINISHED SUCCESSFULLY ##########
########## Generating Info ASUP on netapp2 ##########
[Fri Jul 19 09:21:04 2013] INFO: ASUP create on netapp2 finished successfully
########## Checking Protection Manager dataset snapcreator_dfsupmvintp01_snap ##########
[Fri Jul 19 09:21:04 2013] INFO: Checking if Protection Manager dataset snapcreator_dfsupmvintp01_snap is conformant
[Fri Jul 19 09:21:04 2013] INFO: Protection Manager dataset snapcreator_dfsupmvintp01_snap is conformant
[Fri Jul 19 09:21:04 2013] WARN: Protection Manager dataset snapcreator_dfsupmvintp01_snap resource status error
[Fri Jul 19 09:21:04 2013] INFO: Performing Protection Manager dataset verify for snapcreator_dfsupmvintp01_snap
[Fri Jul 19 09:21:04 2013] INFO: Protection Manager dataset changes not detected
[Fri Jul 19 09:21:04 2013] INFO: Protection Manager dataset verify for snapcreator_dfsupmvintp01_snap completed successfully
########## Gathering Information for netapp2:FileServer_vol11 ##########
[Fri Jul 19 09:21:04 2013] INFO: Performing Snapshot Inventory for FileServer_vol11 on netapp2
[Fri Jul 19 09:21:05 2013] INFO: Snapshot Inventory of FileServer_vol11 on netapp2 completed Successfully
########## Creating Protection Manager Backup Version for volume FileServer_vol11 dataset snapcreator_dfsupmvintp01_snap ##########
[Fri Jul 19 09:21:05 2013] INFO: Finding all members associated with Protection Manager dataset snapcreator_dfsupmvintp01_snap
[Fri Jul 19 09:21:05 2013] INFO: All members of Protection Manager dataset snapcreator_dfsupmvintp01_snap Successfully discovered
[Fri Jul 19 09:21:05 2013] INFO: Added member netapp2:/FileServer_vol11/- from dataset snapcreator_dfsupmvintp01_snap to Protection Manager Backup Version
########## Running Protection Manager Backup Version Create for dataset snapcreator_dfsupmvintp01_snap ##########
[Fri Jul 19 09:21:05 2013] INFO: Registering snapshot dfsupmvintp01-hourly_20130719092000 with Protection Manager dataset snapcreator_dfsupmvintp01_snap
[Fri Jul 19 09:21:05 2013] INFO: Snapshot(s) for dataset snapcreator_dfsupmvintp01_snap registered with Protection Manager successfully
########## Running Protection Manager backup start for dataset snapcreator_dfsupmvintp01_snap ##########
[Fri Jul 19 09:21:05 2013] INFO: Starting Protection Manager backup
[Fri Jul 19 09:21:05 2013] INFO: Protection Manager backup start completed successfully
########## Getting Protection Manager backup progress ##########
[Fri Jul 19 09:21:15 2013] INFO: Getting Protection Manager backup progress for job-id 177115
[Fri Jul 19 09:21:16 2013] INFO: Protection Manager backup progress get for job-id 177115 completed successfully
[Fri Jul 19 09:21:16 2013] INFO: Protection Manager backup for job-id 177115 is running, Sleeping 1 minute
[Fri Jul 19 09:22:16 2013] INFO: Getting Protection Manager backup progress for job-id 177115
[Fri Jul 19 09:22:17 2013] INFO: Protection Manager backup progress get for job-id 177115 completed successfully
[Fri Jul 19 09:22:17 2013] INFO: Protection Manager backup for job-id 177115 is running, Sleeping 1 minute
[Fri Jul 19 09:23:17 2013] INFO: Getting Protection Manager backup progress for job-id 177115
[Fri Jul 19 09:23:18 2013] INFO: Protection Manager backup progress get for job-id 177115 completed successfully
[Fri Jul 19 09:23:18 2013] INFO: Protection Manager backup for job-id 177115 is running, Sleeping 1 minute
[Fri Jul 19 09:24:18 2013] INFO: Getting Protection Manager backup progress for job-id 177115
[Fri Jul 19 09:24:20 2013] INFO: Protection Manager backup progress get for job-id 177115 completed successfully
[Fri Jul 19 09:24:20 2013] ERROR: [scf-00099] Protection Manager backup for job-id 177115 completed with errors - 2642852|error|snapmirror-end|SnapMirror transfer failed.
########## PRE EXIT COMMANDS ##########
[Fri Jul 19 09:24:20 2013] INFO: No commands defined
########## PRE EXIT COMMANDS FINISHED SUCCESSFULLY ##########
[Fri Jul 19 09:24:20 2013] INFO: Creating OM Event (script:critical-event) on sys56
[Fri Jul 19 09:24:20 2013] INFO: OM Event (script:critical-event) on sys56 created successfully
DFM LOG
A Critical event at 19 Jul 09:20 EDT on Mgmt Station sys56:
Script: Critical Event.
SNAPCREATOR [scf-00099] Protection Manager backup for job-id 177115 completed with errors - 2642852|error|snapmirror-end|SnapMirror transfer failed. (Config: dfsupmvintp01_snap Name: dfsupmvintp01 Policy: hourly)
Click below to see the details of this event.
http://sys56:8080/start.html#st=1&data=(eventID=704318)
*** Event details follow.***
General Information
-------------------
DataFabric Manager server Serial Number: 1-50-130179 Alarm Identifier: 4
Event Fields
-------------
Event Identifier: 704318
Event Name: Script: Critical Event
Event Description: Script Generated event Event Severity: Critical Event Timestamp: 19 Jul 09:20
Source of Event
---------------
Source Identifier: 1
Source Name: sys56
Source Type: Mgmt Station
Source Status: Critical
Event Arguments
---------------
script-condition: SNAPCREATOR [scf-00099] Protection Manager backup for job-id 177115 completed with errors - 2642852|error|snapmirror-end|SnapMirror transfer failed. (Config: dfsupmvintp01_snap Name: dfsupmvintp01 Policy: hourly)
--NetApp DataFabric Manager
