Re: Protection Manager shows failed SnapMirror update and filer shows the mirror completed successfu...

rodrigue · ‎2013-07-19

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

sivar · ‎2013-07-19

Hello Rodrigue,

Please provide me with the below details.

You may email me to sivar @ netapp.com

Please login to your DFM server (Is it windows?) and get me the below output.

dfm host get netapp2

dfm host get <fillinyourdrfilername>

dfm host diag netapp2

dfm host diag <fillinyourdrfilername>

and

dfm option list

rodrigue · ‎2013-07-19

Ok. One sec -- working on it.

rodrigue · ‎2013-07-19

I cannot figure out how to attach but in any case, here it is. I have included the dfm get for all the filers.

Script started on Fri 19 Jul 2013 10:09:49 AM EDT

[root@sys56 ~]# dfm host n get netapp1

Host: netapp1.fldoi.gov

Login: root

Password: ********

Login Protocol: ssh

Preferred IP address 1:

Preferred IP address 2:

Primary IP Address: 172.17.80.22

Remote Platform Management IP Address:

Console Terminal Server Address:

Host CPU Too Busy Threshold (%): 95

Host CPU Busy Threshold Interval: 00:15:00

Ping Method: echo_snmp

Administration Transport: https

NDMP Login: ndmpuser

NDMP Password: ********

Administration Port: 443

Performance Advisor Transport: httpsOk

Preferred SNMP Version: 1

Hosts.equiv Enabled: No

Maximum Active Data Transfers:

Performance Advisor Data Export Enabled: No

Host vFiler Default Interface:

Primary IP Address Inconsistency Action:

Automatically collect per-client statistics: No

Host clock skew threshold: 1 minute

Host clock nearly skewed threshold: 30 seconds

[root@sys56 ~]# dfm host get netapp1 2

Host: netapp2.fldoi.gov

Login: root

Password: ********

Login Protocol: ssh

Preferred IP address 1:

Preferred IP address 2:

Primary IP Address: 172.17.80.24

Remote Platform Management IP Address:

Console Terminal Server Address:

Host CPU Too Busy Threshold (%): 95

Host CPU Busy Threshold Interval: 00:15:00

Ping Method: echo_snmp

Administration Transport: https

NDMP Login: ndmpuser

NDMP Password: ********

Administration Port: 443

Performance Advisor Transport: httpsOk

Preferred SNMP Version: 1

Hosts.equiv Enabled: No

Maximum Active Data Transfers:

Performance Advisor Data Export Enabled: No

Host vFiler Default Interface:

Primary IP Address Inconsistency Action:

Automatically collect per-client statistics: No

Host clock skew threshold: 1 minute

Host clock nearly skewed threshold: 30 seconds

[root@sys56 ~]# dfm host get netapp2 3

Host: netapp3.fldoi.gov

Login: administrator

Password: ********

Login Protocol: ssh

Preferred IP address 1:

Preferred IP address 2:

Primary IP Address: 158.229.72.10

Remote Platform Management IP Address:

Console Terminal Server Address:

Host CPU Too Busy Threshold (%): 95

Host CPU Busy Threshold Interval: 00:15:00

Ping Method: echo_snmp

Administration Transport: https

NDMP Login: ndmpuser

NDMP Password: ********

Administration Port: 443

Performance Advisor Transport: httpsOk

Preferred SNMP Version: 1

Hosts.equiv Enabled: No

Maximum Active Data Transfers:

Performance Advisor Data Export Enabled: No

Host vFiler Default Interface:

Primary IP Address Inconsistency Action:

Automatically collect per-client statistics: No

Host clock skew threshold: 1 minute

Host clock nearly skewed threshold: 30 seconds

[root@sys56 ~]# dfm host get netapp3 4

Host: netapp4.fldoi.gov

Login: administrator

Password: ********

Login Protocol: ssh

Preferred IP address 1:

Preferred IP address 2:

Primary IP Address: 158.229.72.11

Remote Platform Management IP Address:

Console Terminal Server Address:

Host CPU Too Busy Threshold (%): 95

Host CPU Busy Threshold Interval: 00:15:00

Ping Method: echo_snmp

Administration Transport: https

NDMP Login: ndmpuser

NDMP Password: ********

Administration Port: 443

Performance Advisor Transport: httpsOk

Preferred SNMP Version: 1

Hosts.equiv Enabled: No

Maximum Active Data Transfers:

Performance Advisor Data Export Enabled: No

Host vFiler Default Interface:

Primary IP Address Inconsistency Action:

Automatically collect per-client statistics: No

Host clock skew threshold: 1 minute

Host clock nearly skewed threshold: 30 seconds

[root@sys56 ~]# dfm host get netapp4 backuop1 p1

Host: backup1.fldoi.gov

Login: root

Password: ********

Login Protocol: ssh

Preferred IP address 1:

Preferred IP address 2:

Primary IP Address: 172.17.80.32

Remote Platform Management IP Address:

Console Terminal Server Address:

Host CPU Too Busy Threshold (%): 95

Host CPU Busy Threshold Interval: 00:15:00

Ping Method: echo_snmp

Administration Transport: https

NDMP Login: ndmpuser

NDMP Password: ********

Administration Port: 443

Performance Advisor Transport: httpsOk

Preferred SNMP Version: 1

Hosts.equiv Enabled: No

Maximum Active Data Transfers:

Performance Advisor Data Export Enabled: No

Host vFiler Default Interface:

Primary IP Address Inconsistency Action:

Automatically collect per-client statistics: No

Host clock skew threshold: 1 minute

Host clock nearly skewed threshold: 30 seconds

[root@sys56 ~]# dfm options list

Option Value

------------------------------------- ------------------------------

agentHostAdminPassword ********

agentHostCIFSAccount

agentHostCIFSPassword ********

agentHostGuestPassword ********

agentHostLogin guest

agentHostPort 4092

agentHostTransport http

agentMonInterval 2 minutes

aggrFullThreshold 90

aggrFullThresholdInterval 0 seconds

aggrNearlyFullThreshold 80

aggrNearlyOvercommittedThreshold 95

aggrNearlyOverDeduplicatedThreshold 150

aggrOvercommittedThreshold 100

aggrOverDeduplicatedThreshold 160

aggrSnapshotFullThreshold 90

aggrSnapshotNearlyFullThreshold 80

alarmScriptRunAs

alertFrom OnCommandCore@noreply-ever.com

auditLogEnabled Enabled

auditLogForever No

authUsePam no

autoClientStatEnabled No

autosupportAdminContact

autosupportContent complete

autosupportDestinationEmail autosupport@netapp.com

autosupportDestinationURL support.netapp.com/asupprod/post/1.0/postAsup

autosupportEnabled Yes

autosupportIncludeAllDiagInfo No

autosupportIncludePerf Yes

autosupportIncludeProv Yes

autosupportIncludeVirtual Yes

autosupportMonInterval 2 minutes

autosupportProtocol https

autosupportRetryCount 4

autosupportRetryDelay 15 minutes

backupDirMonInterval 8 hours

backupRetentionCount 4

ccMonInterval 4 hours

cfMonInterval 5 minutes

chargebackDayOfMonth 1

chargebackIncrement Daily

chargebackRate

clientStatCifsLatency 30

clientStatCpuThreshold 80

clientStatMinTotalOpsRate 500

clientStatNfsLatency 30

clientStatThresholdPeriod 300

clientStatTotalOpsRate 30

clusterMonInterval Off

cpuBusyThresholdInterval 15 minutes

cpuMonInterval 5 minutes

cpuTooBusyThreshold 95

credCacheTTL 20 minutes

currencyFormat $ #,###.##

currentEventsCacheSize

databaseBackupDbengWaitTime 600

databaseBackupDir /opt/NTAPdfm/data/

dataExportDir /opt/NTAPdfm/dataExport/

dataTransferReports Enabled

defReportLinesPerPage 20

deletePrimaryOSSVDirectory No

dfmDataExportEnabled No

dfmencKeysDir /opt/NTAPdfm/conf/keys

dfMonInterval 30 minutes

discoverAgents Enabled

discoverClusters Disabled

discoverEnabled Enabled

discoverHostInitEnabled Enabled

discoverHosts Enabled

discoverInterval 15 minutes

discoverNetworks Disabled

discoverTimeout 5 seconds

discoverVfilers Enabled

diskMonInterval 4 hours

dpDynamicSecondarySizing Enabled

dpMaxFanInRatio 1

dpPriVolNameFormat %L

dpPriVolNameOption global-format

dpPriVolNameScriptPath

dpPriVolNameScriptRunAs

dpReaperCleanupMode Orphans

dpReaperInterval 30 minutes

dpReBaselineMode Confirm

dpRestoreTransfersPerHost 8

dpSecQtreeNameFormat %Q

dpSecVolNameFormat %V

dpSecVolNameOption global-format

dpSecVolNameScriptPath

dpSecVolNameScriptRunAs

dpSnapNameFormat %T_%R_%L_%H_%N_%A

dpSnapNameOption global-format

dpSnapNameScriptPath

dpSnapNameScriptRunAs

dsConformanceMonInterval 1 hour

dsDRMonInterval 15 minutes

dsProtectionMonInterval 15 minutes

dsUsageMetricCommentFields

dsUsageMetricIoInterval 1 day

dsUsageMetricMonInterval 2 hours

dsUsageMetricSpaceInterval 1 day

enableFQDNInFilerViewLinks Enabled

envMonInterval 5 minutes

eventsPurgeInterval 25.71 weeks

favoriteMaxReports 25

filerConfigSaveLocalChanges yes

fsMonInterval 15 minutes

groupTreeShowStatus Enabled

growthRateSensitivity 2

guiRefreshInterval 00:05:00

hbaportTooBusyThreshold 90

hostAdminPort 80

hostAdminTransport http

hostClockNearlySkewedThreshold 30 seconds

hostClockSkewedThreshold 1 minute

hostEnclosureDiscoveryEvents Disabled

hostLoginProtocol rsh

hostPingMethod echo_snmp

hostRBACMonInterval 1 day

hsNotificationsMaxCount 100000

hsNotificationsPurgingInterval 86400

httpEnabled Yes

httpPort 8080

httpsEnabled Yes

httpsPort 8443

ifMonInterval 15 minutes

isHsAliveMonInterval 1 minute

keystorePassphraseFile

ldapBaseDN

ldapBindDN

ldapBindPass ********

ldapEnabled No

ldapGID

ldapMember uniqueMember

ldapUGID CN

ldapUID UID

ldapVersion 3

licenseExpireWarningThreshold 5

licenseMonInterval 4 hours

localHostName

lunMonInterval 30 minutes

maxReportLinesPerPage 1000

monMinFreeBytes 10000.0

monMinFreePercent 10.0

monSNMPRetries 4

monSNMPTimeout 60

ndmpDataUseAllInterfaces 0

ndmpMonInterval 30 minutes

networkDiscoveryLimit 15

nodesRemainingWarningThreshold 1

opsMonInterval 10 minutes

ownerEmailFieldName ownerEmail

perfAdvisorEnabled Enabled

perfAdvisorMaxMonitorThreads 32

perfAdvisorPollInterval 5 minutes

perfAdvisorShowAllViews Disabled

perfAdvisorShowDiagCounters Disabled

perfAdvisorTransport httpOnly

perfAdvThreshViolationMonInterval 15 minutes

perfArchiveDir /opt/NTAPdfm/perfdata

perfDataExportEnabled No

perfExportDir /opt/NTAPdfm/perfExport

perfMaxObjectInstancesInBarChart 20

perfSampleRate1 1 minute

perfSampleRate2 5 minutes

perfSampleRate3 15 minutes

perfSampleRate4 30 minutes

pingMonInterval 1 minute

pingMonRetryDelay 3

pingMonTimeout 3

pluginsDir /opt/NTAPdfm/plugins

pmQSMBackupPreferred No

pmUseSDUCompatibleSnapshotNames No

preferredIPAddressType IPv4

processHostPrimaryAddress off

processOSSVPrimaryAddress warn

profileTTL 6.43 weeks

protMgrNodesRemainingWarningThreshold 1

provMgrNodesRemainingWarningThreshold 1

qtreeFullThreshold 90

qtreeFullThresholdInterval 0 seconds

qtreeGrowthEventMinChangePct 1

qtreeMonInterval 8 hours

qtreeNearlyFullThreshold 80

recentMaxReports 25

reportDesignPath /opt/NTAPdfm/reports/

reportsArchiveDir /opt/NTAPdfm/reports/

respoolFullThreshold 90

respoolNearlyFullThreshold 80

respoolSpaceMonInterval 1 hour

rshBinary

SANHostMonInterval 5 minutes

SANHostMonSnapshotLUNs Enabled

scriptDir /opt/NTAPdfm/script-plugins

scriptPath

serverAPILogExclude host-service-discover|dfm-about

serverCertAuthEnabled Enabled

serverHTTPEnabled Disabled

serverHTTPPort 8088

serverHTTPSEnabled Enabled

serverHTTPSPort 8488

shareMonInterval 1 hour

SMTPServerBackup

SMTPServerName localhost

SMTPServerPort 25

snapmirrorLagErrorThreshold 2 days, 0:00

snapmirrorLagWarningThreshold 1 day, 12:00

snapmirrorMonInterval 30 minutes

snapshotDiscoveryEventsEnabled No

snapshotMonInterval 30 minutes

snapvaultMonInterval 30 minutes

snmpTrapListenerEnabled Yes

snmpTrapListenerPort 162

snmpTrapRcvdMaxPerWindow 250

snmpTrapRcvdWindowSize 5 minutes

statusMonInterval 10 minutes

sysInfoMonInterval 1 hour

useHostsEquiv No

userEmailDefaultDomain

userEnableAlerts yes

userFullThreshold 90

userNearlyFullThreshold 80

userQuotaMonInterval 1 day

vFilerMonInterval 1 hour

vFilerRootVolumeSizeMb 50

volFullThreshold 90

volFullThresholdInterval 0 seconds

volGrowthEventMinChangePct 1

volNearlyFullThreshold 80

volNearlyNoFirstSnapThreshold 80

volNearlyOvercommittedThreshold 95

volNearlyOverDeduplicatedThreshold 140

volNoFirstSnapThreshold 90

volOvercommittedThreshold 100

volOverDeduplicatedThreshold 150

volReserveDepletedThreshold 90

volReserveNearlyDepletedThreshold 80

volSnapshotCountThreshold 250

volSnapshotFullThreshold 90

volSnapshotTooOldThreshold 52 weeks

vserverMonInterval Off

webUIMaxHeapSizeMB 1024

webUIMaxPermGenSizeMB 512

webUIMinHeapSizeMB 256

webUIMinPermGenSizeMB 128

webUIPort 8123

[root@sys56 ~]# exit

Script done on Fri 19 Jul 2013 10:10:18 AM EDT

sivar · ‎2013-07-19

All you NetApp Storage controllers are configured to use ssh as the protocol (from DFM perspective),

where as the default hostLoginProtocol is set as rsh.

Windows server cannot spawn the rsh command so it reports this error then executes via ssh and succeeds. (this is why your snapmirror updates are successful, but meanwhile, SC is kicked out with a failed message)

If you set your

hostLoginProtocol

rsh

from rsh to ssh - you will not have this SC failures anymore.

hostLoginProtocol

ssh

The way to change this option is

dfm option set hostLoginProtocol=ssh

FYI - This is a global option in DFM

rodrigue · ‎2013-07-19

the DFM server is running on linux btw.

rodrigue · ‎2013-07-19

that didn't do it! They are still failing.

rodrigue · ‎2013-07-19

that didn't do it! They are still failing.

sivar · ‎2013-07-19

Ok. I will check with my DFM experts.

What I am noticing is the snapmirror update fails exactly after 5 minutes...looks like a timeout setting somewhere.

I will get back to you soon.

sivar · ‎2013-07-19

dfm job details 177115

Please collect me the about output.

I will have my DFM expert review it

rodrigue · ‎2013-07-19

will do in a few minutes

rodrigue · ‎2013-07-19

Job Id: 177115

Job State: completed

Job Description: Snap Creator Framework Initiated Backup

Job Type: on_demand_backup

Job Status: partial_success

Bytes Transferred: 0

Dataset Name: snapcreator_dfsupmvintp01_snap

Dataset Id: 14246

Object Name: snapcreator_dfsupmvintp01_snap

Object Id: 14246

Policy Name: Fileserver DR Mirror and back up on the three quarter hour

Policy Id: 14082

Started Timestamp: 19 Jul 2013 09:17:35

Abort Requested Timestamp:

Completed Timestamp: 19 Jul 2013 09:20:21

Submitted By: netapp

Job progress messages:

Event Id: 2642760

Event Status: normal

Event Type: job-start

Job Id: 177115

Timestamp: 19 Jul 2013 09:17:35

Message:

Error Message:

Event Id: 2642766

Event Status: normal

Event Type: job-progress

Job Id: 177115

Timestamp: 19 Jul 2013 09:17:40

Message: Dynamic secondary volume sizing is enabled.

Error Message:

Event Id: 2642768

Event Status: normal

Event Type: job-progress

Job Id: 177115

Timestamp: 19 Jul 2013 09:17:40

Message: Bandwidth limit for the job is UNLIMITED.

Error Message:

Event Id: 2642769

Event Status: normal

Event Type: snapmirror-start

Job Id: 177115

Timestamp: 19 Jul 2013 09:17:40

Message: Starting SnapMirror transfer.

Error Message:

Source Id: 8499

Source Name: netapp2:/FileServer_vol11

Destination Id: 13682

Destination Name: netapp4:/FileServer_vol11_SnapMirror_12072013_145025

Bytes Transferred: 0

Event Id: 2642771

Event Status: error

Event Type: snapmirror-progress

Job Id: 177115

Timestamp: 19 Jul 2013 09:17:42

Message:

Error Message: netapp4.fldoi.gov: transfer attempted for busy destination

Source Id: 8499

Source Name: netapp2:/FileServer_vol11

Destination Id: 13682

Destination Name: netapp4:/FileServer_vol11_SnapMirror_12072013_145025

Bytes Transferred: 0

Event Id: 2642772

Event Status: normal

Event Type: snapmirror-progress

Job Id: 177115

Timestamp: 19 Jul 2013 09:17:42

Message: Approximately 0 MB received so far (Transferring; SnapMirrored)

Error Message:

Source Id: 8499

Source Name: netapp2:/FileServer_vol11

Destination Id: 13682

Destination Name: netapp4:/FileServer_vol11_SnapMirror_12072013_145025

Bytes Transferred: 0

Event Id: 2642773

Event Status: normal

Event Type: snapmirror-progress

Job Id: 177115

Timestamp: 19 Jul 2013 09:17:42

Message:

Error Message: GENERIC

Source Id: 8499

Source Name: netapp2:/FileServer_vol11

Destination Id: 13682

Destination Name: netapp4:/FileServer_vol11_SnapMirror_12072013_145025

Bytes Transferred: 0

Event Id: 2642774

Event Status: error

Event Type: snapmirror-end

Job Id: 177115

Timestamp: 19 Jul 2013 09:17:42

Message:

Error Message: SnapMirror transfer failed.

Source Id: 8499

Source Name: netapp2:/FileServer_vol11

Destination Id: 13682

Destination Name: netapp4:/FileServer_vol11_SnapMirror_12072013_145025

Bytes Transferred: 0

Event Id: 2642800

Event Status: normal

Event Type: job-progress

Job Id: 177115

Timestamp: 19 Jul 2013 09:18:46

Message: operation was successful

Error Message:

Event Id: 2642805

Event Status: normal

Event Type: job-progress

Job Id: 177115

Timestamp: 19 Jul 2013 09:19:00

Message: operation was successful

Error Message:

Event Id: 2642806

Event Status: normal

Event Type: job-progress

Job Id: 177115

Timestamp: 19 Jul 2013 09:19:00

Message: Found 1 backup relationships in the dataset.

Error Message:

Event Id: 2642808

Event Status: normal

Event Type: job-progress

Job Id: 177115

Timestamp: 19 Jul 2013 09:19:00

Message: Retrieving preferred interfaces

Error Message:

Event Id: 2642809

Event Status: normal

Event Type: job-progress

Job Id: 177115

Timestamp: 19 Jul 2013 09:19:01

Message: Retrieved preferred interfaces (172.17.80.24)

Error Message:

Event Id: 2642810

Event Status: normal

Event Type: job-progress

Job Id: 177115

Timestamp: 19 Jul 2013 09:19:01

Message: Dynamic secondary volume sizing is enabled.

Error Message:

Event Id: 2642811

Event Status: normal

Event Type: job-progress

Job Id: 177115

Timestamp: 19 Jul 2013 09:19:02

Message: DSS: Determining if secondary volume backup1:/FileServer_vol11_FileServer_vol11_SnapVault (13756) needs resizing.

Error Message:

Event Id: 2642812

Event Status: normal

Event Type: job-progress

Job Id: 177115

Timestamp: 19 Jul 2013 09:19:02

Message: DSS: Secondary volume backup1:/FileServer_vol11_FileServer_vol11_SnapVault (13756):

current total=3332649MB,

current used=515697MB,

new total=3032280MB,

volume margin=10%,

adjusted new total=3335508MB,

resize_up_only=0.

Secondary Volume Size Limits:

Opt DSS Max=0MB,

Limit to Aggr ("No")=82248399MB,

Dedupe Enabled ("No")=16777216MB,

Max Vol Limit=82248399MB.

Error Message:

Event Id: 2642813

Event Status: normal

Event Type: job-progress

Job Id: 177115

Timestamp: 19 Jul 2013 09:19:02

Message: Transferring backup 232034, version 19 Jul 09:21 EDT.

Error Message:

Event Id: 2642814

Event Status: normal

Event Type: snapvault-start

Job Id: 177115

Timestamp: 19 Jul 2013 09:19:02

Message:

Error Message:

Source Qtree Id: 8507

Source Qtree Name: netapp2:/FileServer_vol11/-

Destination Qtree Id: 13759

Destination Qtree Name: backup1:/FileServer_vol11_FileServer_vol11_SnapVault/FileServer_vol11_netapp2_FileServer_vol11

Bytes Transferred: 0

Event Id: 2642815

Event Status: normal

Event Type: snapvault-progress

Job Id: 177115

Timestamp: 19 Jul 2013 09:19:03

Message: Backing up netapp2:/FileServer_vol11/- via 172.17.80.24

Error Message:

Source Qtree Id: 8507

Source Qtree Name: netapp2:/FileServer_vol11/-

Destination Qtree Id: 13759

Destination Qtree Name: backup1:/FileServer_vol11_FileServer_vol11_SnapVault/FileServer_vol11_netapp2_FileServer_vol11

Bytes Transferred: 0

Event Id: 2642816

Event Status: normal

Event Type: snapvault-progress

Job Id: 177115

Timestamp: 19 Jul 2013 09:19:06

Message: operation was successful

Error Message:

Source Qtree Id: 8507

Source Qtree Name: netapp2:/FileServer_vol11/-

Destination Qtree Id: 13759

Destination Qtree Name: backup1:/FileServer_vol11_FileServer_vol11_SnapVault/FileServer_vol11_netapp2_FileServer_vol11

Bytes Transferred: 0

Event Id: 2642833

Event Status: normal

Event Type: snapvault-progress

Job Id: 177115

Timestamp: 19 Jul 2013 09:19:44

Message: operation was successful

Error Message:

Source Qtree Id: 8507

Source Qtree Name: netapp2:/FileServer_vol11/-

Destination Qtree Id: 13759

Destination Qtree Name: backup1:/FileServer_vol11_FileServer_vol11_SnapVault/FileServer_vol11_netapp2_FileServer_vol11

Bytes Transferred: 0

Event Id: 2642834

Event Status: normal

Event Type: snapvault-end

Job Id: 177115

Timestamp: 19 Jul 2013 09:19:44

Message:

Error Message:

Source Qtree Id: 8507

Source Qtree Name: netapp2:/FileServer_vol11/-

Destination Qtree Id: 13759

Destination Qtree Name: backup1:/FileServer_vol11_FileServer_vol11_SnapVault/FileServer_vol11_netapp2_FileServer_vol11

Bytes Transferred: 0

Event Id: 2642836

Event Status: normal

Event Type: job-progress

Job Id: 177115

Timestamp: 19 Jul 2013 09:20:05

Message: Using global-format in global options for snapshot naming in dataset snapcreator_dfsupmvintp01_snap

Error Message:

Event Id: 2642837

Event Status: normal

Event Type: job-progress

Job Id: 177115

Timestamp: 19 Jul 2013 09:20:05

Message: Using naming format %T_%R_%L_%H_%N_%A to create the snapshot name for dataset snapcreator_dfsupmvintp01_snap

Error Message:

Event Id: 2642838

Event Status: normal

Event Type: job-progress

Job Id: 177115

Timestamp: 19 Jul 2013 09:20:05

Message: operation was successful

Error Message:

Event Id: 2642847

Event Status: normal

Event Type: job-progress

Job Id: 177115

Timestamp: 19 Jul 2013 09:20:20

Message: The create snapshot operation completed successfully.

Error Message:

Event Id: 2642848

Event Status: normal

Event Type: job-progress

Job Id: 177115

Timestamp: 19 Jul 2013 09:20:20

Message: operation was successful

Error Message:

Event Id: 2642849

Event Status: normal

Event Type: snapshot-create

Job Id: 177115

Timestamp: 19 Jul 2013 09:20:20

Message:

Error Message:

Volume Id: 13756

Volume Name: backup1:/FileServer_vol11_FileServer_vol11_SnapVault

Snapshot Name: 2013-07-19_0920-0400_hourly_snapcreator_dfsupmvintp01_snap_backup1_FileServer_vol11_FileServer_vol11_SnapVault_.-.FileServer

Event Id: 2642850

Event Status: normal

Event Type: backup-create

Job Id: 177115

Timestamp: 19 Jul 2013 09:20:20

Message:

Error Message:

backup-version: 19 Jul 2013 09:21:00

Backup Id: 232047

Retention Type: hourly

Event Id: 2642852

Event Status: normal

Event Type: job-end

Job Id: 177115

Timestamp: 19 Jul 2013 09:20:21

Message:

Error Message:

sivar · ‎2013-07-19

netapp4:/FileServer_vol11_SnapMirror_12072013_145025

is showing up as busy volume.

This basically means that an ongoing transfer is happening on that volume.

Please get me the below output.

snapmirror status on the netapp4 and get me the status for the above volume.

dfpm job list -d 142416 -v jobs-running

Event Id: 2642771

Event Status: error

Event Type: snapmirror-progress

Job Id: 177115

Timestamp: 19 Jul 2013 09:17:42

Message:

Error Message: netapp4.fldoi.gov: transfer attempted for busy destination

Source Id: 8499

Source Name: netapp2:/FileServer_vol11

Destination Id: 13682

Destination Name: netapp4:/FileServer_vol11_SnapMirror_12072013_145025

Bytes Transferred: 0

Protection Manager shows failed SnapMirror update and filer shows the mirror completed successfully