Solved: SC 3.4 Protection Manager integration issue

pierrek · ‎2011-11-11

Hi All,

I have an issue trying to make SC 3.4 work with PM. I have a configuration making an online backup of Oracle on a linux host (Oracle on NFS).

Then the idea is to use PM to mirror then backup the SC created snapshots to 2 alternate controllers.

A single linux host is involved (no scAgent used) (it's the Oracle server and the DFM/PM server as well)

the primary data is on a filer called ontap-802-src (running Ontap 802)

the mirrored data is located on ontap-802-drp

the snapvault destination volume is on ontap-802-dst

The backup works fine, the final status of the job is always successful, but the application consistent snapshot transfer to ontap-802-dst never happens because of the following fact:

Event Id: 12098

Event Status: normal

Event Type: job-progress

Job Id: 765

Timestamp: 11 Nov 2011 18:11:32

Message: Could not find any backups to transfer on Mirror node of application dataset snapcreator_ntap_full_01(894).

Error Message:

Here are the details of my configuration called ntap_full_01:

########################

### Required Options ###

########################

CONFIG_TYPE=STANDARD

SNAME=snapcreator_ntap_full_01

SNAP_TIMESTAMP_ONLY=Y

VOLUMES=ontap-802-src.netapp.com:v_oractl_01,v_oradata_01,v_oradata_02

NTAP_SNAPSHOT_RETENTIONS=hourly:24

NTAP_USERS=ontap-802-src.netapp.com:root/53616c7465645f5f429c284738d1142f144a856c83d933b4

NTAP_PWD_PROTECTION=Y

TRANSPORT=HTTPS

PORT=443

LOG_NUM=10

SC_TMP_DIR=

########################

### Snapshot Options ###

########################

NTAP_SNAPSHOT_RETENTION_AGE=1

SNAPDRIVE=Y

SNAPDRIVE_DISCOVERY=N

NTAP_SNAPSHOT_DISABLE=N

NTAP_SNAPSHOT_NODELETE=N

NTAP_CONSISTENCY_GROUP_SNAPSHOT=N

NTAP_CONSISTENCY_GROUP_TIMEOUT=medium

NTAP_CONSISTENCY_GROUP_WAFL_SYNC=N

NTAP_SNAPSHOT_DELETE_BY_AGE_ONLY=N

NTAP_SNAPSHOT_DEPENDENCY_IGNORE=N

NTAP_SNAPSHOT_RESTORE_AUTO_DETECT=Y

###################################

### Operations Manager Settings ###

###################################

OM_HOST=orahost1.netapp.com

OM_USER=root

OM_PWD=53616c7465645f5f70912f1eb14e0b9b472b78a894e0471c

OM_PORT=8488

OM_EVENT_GENERATE=Y

##################################

### Protection Manager Options ###

##################################

NTAP_PM_UPDATE=Y

NTAP_DFM_DATA_SET=ontap-802-src.netapp.com:snapcreator_ntap_full_01/v_oractl_01,v_oradata_01,v_oradata_02

# I decided to trigger the PM job on demand (when the primary snapshot has been taken):

NTAP_PM_RUN_BACKUP=Y

# Application specifics:

ORACLE_DATABASES=ntap:oracle

SQLPLUS_CMD=/u01/app/oracle/product/11.2.0/db_1/bin/sqlplus

CNTL_FILE_BACKUP_DIR=/u04/app/oracle/oractl/ntap/backup

ORA_TEMP=/tmp

ARCHIVE_LOG_ONLY=N

ORACLE_HOME=/u01/app/oracle/product/11.2.0/db_1

ORACLE_EXPORT_PARAMETERS=Y

# sapdrive used:

NTAP_SNAPSHOT_CREATE_CMD01=/usr/sbin/snapdrive snap create -fs /u04/app/oracle/oractl/ntap /u02/app/oracle/oradata1/ntap /u02/app/oracle/oradata2/ntap -snapname %SNAME-%SNAP_TYPE_%SNAP_TIME

The Dataset has been created by SC:

[root@orahost1 ~]# dfpm dataset list -x snapcreator_ntap_full_01

Id: 894

Name: snapcreator_ntap_full_01

Policy: Mirror, then back up

Description: Dataset used by NetApp Snap Creator Framework configuration snapcreator_ntap_full_01

Owner:

Contact:

Volume Qtree Name Prefix:

DR Capable: No

Application: NetApp Snap Creator Framework

Version: 3.4.0

Server: Snap Creator Server

Requires Non Disruptive Restore: No

Node details:

Node Name: Primary data

Resource Pools:

Provisioning Policy:

Time Zone:

DR Capable: No

vFiler:

Node Name: Mirror

Resource Pools: DR_pool

Provisioning Policy:

Time Zone:

DR Capable: No

vFiler:

Node Name: Backup

Resource Pools: backup_pool

Provisioning Policy:

Time Zone:

DR Capable: No

vFiler:

[root@orahost1 ~]#

[root@orahost1 ntap]# dfpm policy connection get "Mirror, then back up"

Connection Id: 1

Connection Type: mirror

Origin Node Id: 1

Destination Node Id: 2

Throttle Schedule Id: 0

Throttle Schedule Name:

Mirror Schedule Id: 0 (none) -> I remove the PM schedule for this connection, because it's only triggered on demand

Mirror Schedule Name:

Warning Lag Enabled: Yes

Warning Lag Threshold: 5400

Error Lag Enabled: Yes

Error Lag Threshold: 10800

Disaster Recovery Capable: No

Connection Id: 2

Connection Type: backup

Origin Node Id: 2

Destination Node Id: 3

Throttle Schedule Id: 0

Throttle Schedule Name:

Backup Schedule Id: 0 (none) -> I remove the PM schedule for this connection, because it's only triggered on demand

Backup Schedule Name:

Warning Lag Enabled: Yes

Warning Lag Threshold: 129600

Error Lag Enabled: Yes

Error Lag Threshold: 172800

Disaster Recovery Capable: No

[root@orahost1 ntap]# dfpm policy node get "Mirror, then back up"

Node Id: 1

Node Name: Primary data

Hourly Retention Count: 2

Hourly Retention Duration: 86400

Daily Retention Count: 2

Daily Retention Duration: 604800

Weekly Retention Count: 1

Weekly Retention Duration: 1209600

Monthly Retention Count: 0

Monthly Retention Duration: 0

Backup Script Path:

Backup Script Run As:

Failover Script Path:

Failover Script Run As:

Snapshot Schedule Id: 0

Snapshot Schedule Name:

Warning Lag Enabled: Yes

Warning Lag Threshold: 129600

Error Lag Enabled: Yes

Error Lag Threshold: 172800

Node Id: 2

Node Name: Mirror

Node Id: 3

Node Name: Backup

Hourly Retention Count: 0

Hourly Retention Duration: 2592000 -> retention under PM control

Daily Retention Count: 2

Daily Retention Duration: 1209600

Weekly Retention Count: 2

Weekly Retention Duration: 4838400

Monthly Retention Count: 1

Monthly Retention Duration: 8467200

[root@orahost1 ntap]#

[root@orahost1 ntap]# dfpm relationship list

Relationship Id Relationship Type Dataset Id Dataset Name Source Destination Deleted Deleted By

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

937 volume_snapmirror 894 snapcreator_ntap_full_01 ontap-802-src:/v_oractl_01 ontap-802-drp:/snapcreator_ntap_full_01_mirror_ontap_802_src_v_oractl_01 No

941 volume_snapmirror 894 snapcreator_ntap_full_01 ontap-802-src:/v_oradata_02 ontap-802-drp:/snapcreator_ntap_full_01_mirror_ontap_802_src_v_oradata_02 No

946 snapvault 894 snapcreator_ntap_full_01 ontap-802-drp:/snapcreator_ntap_full_01_mirror_ontap_802_src_v_oradata_02/- ontap-802-dst:/snapcreator_ntap_full_01_backup/snapcreator_ntap_full_01_ontap-802-src_v_oradata_02 No

952 volume_snapmirror 894 snapcreator_ntap_full_01 ontap-802-src:/v_oradata_01 ontap-802-drp:/snapcreator_ntap_full_01_mirror_ontap_802_src_v_oradata_01 No

955 snapvault 894 snapcreator_ntap_full_01 ontap-802-drp:/snapcreator_ntap_full_01_mirror_ontap_802_src_v_oractl_01/- ontap-802-dst:/snapcreator_ntap_full_01_backup_1/snapcreator_ntap_full_01_ontap-802-src_v_oractl_01 No

960 snapvault 894 snapcreator_ntap_full_01 ontap-802-drp:/snapcreator_ntap_full_01_mirror_ontap_802_src_v_oradata_01/- ontap-802-dst:/snapcreator_ntap_full_01_backup_2/snapcreator_ntap_full_01_ontap-802-src_v_oradata_01 No

[root@orahost1 ntap]#

I will now execute a test backup:

List of snapshots taken on primary storage before the test backup is triggered:

[root@orahost1 ~]# snapcreator --action snaplist --profile ntap -config ntap_full_01

########## NetApp Snap Creator Framework Snapshot (Primary) List for ontap-802-src.netapp.com:v_oractl_01 #########

### Snapshot Name ### ### Snapshot Timestamp ###

snapcreator_ntap_full_01-hourly_20111111111926 Nov 11 2011 11:19:37

snapcreator_ntap_full_01-hourly_20111111124057 Nov 11 2011 12:41:05

snapcreator_ntap_full_01-hourly_20111111130000 Nov 11 2011 13:00:11

snapcreator_ntap_full_01-hourly_20111111140000 Nov 11 2011 14:00:16

snapcreator_ntap_full_01-hourly_20111111150000 Nov 11 2011 15:00:17

snapcreator_ntap_full_01-hourly_20111111160000 Nov 11 2011 16:00:16

snapcreator_ntap_full_01-hourly_20111111170000 Nov 11 2011 17:00:13

########## NetApp Snap Creator Framework Snapshot (Primary) List for ontap-802-src.netapp.com:v_oradata_01 #########

### Snapshot Name ### ### Snapshot Timestamp ###

snapcreator_ntap_full_01-hourly_20111111111926 Nov 11 2011 11:19:37

snapcreator_ntap_full_01-hourly_20111111124057 Nov 11 2011 12:41:05

snapcreator_ntap_full_01-hourly_20111111130000 Nov 11 2011 13:00:11

snapcreator_ntap_full_01-hourly_20111111140000 Nov 11 2011 14:00:16

snapcreator_ntap_full_01-hourly_20111111150000 Nov 11 2011 15:00:17

snapcreator_ntap_full_01-hourly_20111111160000 Nov 11 2011 16:00:16

snapcreator_ntap_full_01-hourly_20111111170000 Nov 11 2011 17:00:13

########## NetApp Snap Creator Framework Snapshot (Primary) List for ontap-802-src.netapp.com:v_oradata_02 #########

### Snapshot Name ### ### Snapshot Timestamp ###

snapcreator_ntap_full_01-hourly_20111111111926 Nov 11 2011 11:19:37

snapcreator_ntap_full_01-hourly_20111111124057 Nov 11 2011 12:41:05

snapcreator_ntap_full_01-hourly_20111111130000 Nov 11 2011 13:00:11

snapcreator_ntap_full_01-hourly_20111111140000 Nov 11 2011 14:00:16

snapcreator_ntap_full_01-hourly_20111111150000 Nov 11 2011 15:00:17

snapcreator_ntap_full_01-hourly_20111111160000 Nov 11 2011 16:00:16

snapcreator_ntap_full_01-hourly_20111111170000 Nov 11 2011 17:00:13

[root@orahost1 ~]#

I start the sc config manually:

[root@orahost1 ntap]# snapcreator --profile ntap --config ntap_full_01 --policy hourly --action snap --verbose

[Fri Nov 11 18:06:55 2011] INFO: Removing log ntap_full_01.out.20111111120000

[Fri Nov 11 18:06:55 2011] INFO: Removing log ntap_full_01.debug.20111111120000

########## Parsing Environment Parameters ##########

########## PRE APPLICATION QUIESCE COMMANDS ##########

[Fri Nov 11 18:06:55 2011] INFO: No commands defined

########## PRE APPLICATION QUIESCE COMMANDS FINISHED SUCCESSFULLY ##########

########## Application quiesce ##########

[Fri Nov 11 18:06:55 2011] INFO: Quiescing databases

[Fri Nov 11 18:06:55 2011] INFO: Quiescing database ntap

[Fri Nov 11 18:06:56 2011] INFO: Quiescing database ntap finished successfully

[Fri Nov 11 18:06:56 2011] INFO: Quiescing databases finished successfully

########## POST APPLICATION QUIESCE COMMANDS ##########

[Fri Nov 11 18:06:56 2011] INFO: No commands defined

########## POST APPLICATION QUIESCE COMMANDS FINISHED SUCCESSFULLY ##########

########## PRE NETAPP COMMANDS ##########

[Fri Nov 11 18:06:56 2011] INFO: No commands defined

########## PRE NETAPP COMMANDS FINISHED SUCCESSFULLY ##########

########## Detecting Data OnTap mode for ontap-802-src.netapp.com ##########

[Fri Nov 11 18:06:56 2011] INFO: Data OnTap 7 mode detected

########## Generating Info ASUP on ontap-802-src.netapp.com ##########

[Fri Nov 11 18:06:57 2011] INFO: NetApp ASUP create on ontap-802-src.netapp.com finished successfully

########## Gathering Information for ontap-802-src.netapp.com:v_oractl_01 ##########

[Fri Nov 11 18:06:57 2011] INFO: Performing NetApp Snapshot Inventory for v_oractl_01 on ontap-802-src.netapp.com

[Fri Nov 11 18:06:57 2011] INFO: NetApp Snapshot Inventory of v_oractl_01 on ontap-802-src.netapp.com completed Successfully

########## Gathering Information for ontap-802-src.netapp.com:v_oradata_01 ##########

[Fri Nov 11 18:06:57 2011] INFO: Performing NetApp Snapshot Inventory for v_oradata_01 on ontap-802-src.netapp.com

[Fri Nov 11 18:06:57 2011] INFO: NetApp Snapshot Inventory of v_oradata_01 on ontap-802-src.netapp.com completed Successfully

########## Gathering Information for ontap-802-src.netapp.com:v_oradata_02 ##########

[Fri Nov 11 18:06:57 2011] INFO: Performing NetApp Snapshot Inventory for v_oradata_02 on ontap-802-src.netapp.com

[Fri Nov 11 18:06:57 2011] INFO: NetApp Snapshot Inventory of v_oradata_02 on ontap-802-src.netapp.com completed Successfully

########## Running NetApp Snapshot Rename on Primary ontap-802-src.netapp.com ##########

########## SNAPSHOT CREATE COMMANDS ##########

[Fri Nov 11 18:06:57 2011] INFO: Running snapshot create command NTAP_SNAPSHOT_CREATE_CMD01 [/usr/sbin/snapdrive snap create -fs /u04/app/oracle/oractl/ntap /u02/app/oracle/oradata1/ntap /u02/app/oracle/oradata2/ntap -snapname snapcreator_ntap_full_01-hourly_20111111180655]

[Fri Nov 11 18:07:14 2011] INFO: Running snapshot create command [/usr/sbin/snapdrive snap create -fs /u04/app/oracle/oractl/ntap /u02/app/oracle/oradata1/ntap /u02/app/oracle/oradata2/ntap -snapname snapcreator_ntap_full_01-hourly_20111111180655] finished successfully

########## SNAPSHOT CREATE COMMANDS FINISHED SUCCESSFULLY ##########

########## PRE APPLICATION UNQUIESCE COMMANDS ##########

[Fri Nov 11 18:07:14 2011] INFO: No commands defined

########## PRE APPLICATION UNQUIESCE COMMANDS FINISHED SUCCESSFULLY ##########

########## Application unquiesce ##########

[Fri Nov 11 18:07:14 2011] INFO: Unquiescing databases

[Fri Nov 11 18:07:14 2011] INFO: Unquiescing database ntap

[Fri Nov 11 18:07:18 2011] INFO: Unquiescing database ntap finished successfully

[Fri Nov 11 18:07:18 2011] INFO: Unquiescing databases finished successfully

########## POST APPLICATION UNQUIESCE COMMANDS ##########

[Fri Nov 11 18:07:18 2011] INFO: No commands defined

########## POST APPLICATION UNQUIESCE COMMANDS FINISHED SUCCESSFULLY ##########

########## Generating Info ASUP on ontap-802-src.netapp.com ##########

[Fri Nov 11 18:07:19 2011] INFO: NetApp ASUP create on ontap-802-src.netapp.com finished successfully

########## Checking Protection Manager dataset snapcreator_ntap_full_01 ##########

[Fri Nov 11 18:07:19 2011] INFO: Checking if Protection Manager dataset snapcreator_ntap_full_01 is conformant

[Fri Nov 11 18:07:19 2011] INFO: Protection Manager dataset snapcreator_ntap_full_01 is conformant

[Fri Nov 11 18:07:19 2011] INFO: Protection Manager dataset snapcreator_ntap_full_01 resource status normal

########## Gathering Information for ontap-802-src.netapp.com:v_oractl_01 ##########

[Fri Nov 11 18:07:19 2011] INFO: Performing NetApp Snapshot Inventory for v_oractl_01 on ontap-802-src.netapp.com

[Fri Nov 11 18:07:19 2011] INFO: NetApp Snapshot Inventory of v_oractl_01 on ontap-802-src.netapp.com completed Successfully

########## Creating Protection Manager Backup Version for volume v_oractl_01 dataset snapcreator_ntap_full_01 ##########

[Fri Nov 11 18:07:19 2011] INFO: Finding all members associated with Protection Manager dataset snapcreator_ntap_full_01

[Fri Nov 11 18:07:22 2011] INFO: All members of Protection Manager dataset snapcreator_ntap_full_01 Successfully discovered

########## Gathering Information for ontap-802-src.netapp.com:v_oradata_01 ##########

[Fri Nov 11 18:07:22 2011] INFO: Performing NetApp Snapshot Inventory for v_oradata_01 on ontap-802-src.netapp.com

[Fri Nov 11 18:07:22 2011] INFO: NetApp Snapshot Inventory of v_oradata_01 on ontap-802-src.netapp.com completed Successfully

########## Creating Protection Manager Backup Version for volume v_oradata_01 dataset snapcreator_ntap_full_01 ##########

[Fri Nov 11 18:07:22 2011] INFO: Finding all members associated with Protection Manager dataset snapcreator_ntap_full_01

[Fri Nov 11 18:07:23 2011] INFO: All members of Protection Manager dataset snapcreator_ntap_full_01 Successfully discovered

########## Gathering Information for ontap-802-src.netapp.com:v_oradata_02 ##########

[Fri Nov 11 18:07:23 2011] INFO: Performing NetApp Snapshot Inventory for v_oradata_02 on ontap-802-src.netapp.com

[Fri Nov 11 18:07:23 2011] INFO: NetApp Snapshot Inventory of v_oradata_02 on ontap-802-src.netapp.com completed Successfully

########## Creating Protection Manager Backup Version for volume v_oradata_02 dataset snapcreator_ntap_full_01 ##########

[Fri Nov 11 18:07:23 2011] INFO: Finding all members associated with Protection Manager dataset snapcreator_ntap_full_01

[Fri Nov 11 18:07:24 2011] INFO: All members of Protection Manager dataset snapcreator_ntap_full_01 Successfully discovered

########## Running NetApp Protection Manager Backup Version Create for dataset snapcreator_ntap_full_01 ##########

[Fri Nov 11 18:07:24 2011] INFO: Registering snapshot snapcreator_ntap_full_01-hourly_20111111180655 with Protection Manager dataset snapcreator_ntap_full_01

[Fri Nov 11 18:07:24 2011] INFO: Snapshot snapcreator_ntap_full_01-hourly_20111111180655 for dataset snapcreator_ntap_full_01 registered with Protection Manager successfully --> Here we see the backup is registered to PM

########## Running NetApp Protection Manager backup start for dataset snapcreator_ntap_full_01 ##########

[Fri Nov 11 18:07:24 2011] INFO: Starting NetApp Protection Manager backup

[Fri Nov 11 18:07:24 2011] INFO: NetApp Protection Manager backup start completed successfully

########## Getting Protection Manager backup progress ##########

[Fri Nov 11 18:07:34 2011] INFO: Getting NetApp Protection Manager backup progress for job-id 765

[Fri Nov 11 18:07:35 2011] INFO: NetApp Protection Manager backup progress get for job-id 765 completed successfully

[Fri Nov 11 18:07:35 2011] INFO: NetApp Protection Manager backup for job-id 765 is running, Sleeping 1 minute

[Fri Nov 11 18:08:35 2011] INFO: Getting NetApp Protection Manager backup progress for job-id 765

[Fri Nov 11 18:08:36 2011] INFO: NetApp Protection Manager backup progress get for job-id 765 completed successfully

[Fri Nov 11 18:08:36 2011] INFO: NetApp Protection Manager backup for job-id 765 is running, Sleeping 1 minute

[Fri Nov 11 18:09:36 2011] INFO: Getting NetApp Protection Manager backup progress for job-id 765

[Fri Nov 11 18:09:37 2011] INFO: NetApp Protection Manager backup progress get for job-id 765 completed successfully

[Fri Nov 11 18:09:37 2011] INFO: NetApp Protection Manager backup for job-id 765 is running, Sleeping 1 minute

[Fri Nov 11 18:10:37 2011] INFO: Getting NetApp Protection Manager backup progress for job-id 765

[Fri Nov 11 18:10:38 2011] INFO: NetApp Protection Manager backup progress get for job-id 765 completed successfully

[Fri Nov 11 18:10:38 2011] INFO: NetApp Protection Manager backup for job-id 765 is running, Sleeping 1 minute

[Fri Nov 11 18:11:38 2011] INFO: Getting NetApp Protection Manager backup progress for job-id 765

[Fri Nov 11 18:11:39 2011] INFO: NetApp Protection Manager backup progress get for job-id 765 completed successfully

[Fri Nov 11 18:11:39 2011] INFO: NetApp Protection Manager backup for job-id 765 completed successfully

########## POST NETAPP DATA TRANSFER COMMANDS ##########

[Fri Nov 11 18:11:39 2011] INFO: No commands defined

########## POST NETAPP DATA TRANSFER COMMANDS FINISHED SUCCESSFULLY ##########

########## Running NetApp Snapshot Delete on Primary ontap-802-src.netapp.com ##########

########## Running NetApp PM Version Delete ##########

########## POST NETAPP COMMANDS ##########

[Fri Nov 11 18:11:39 2011] INFO: No commands defined

########## POST NETAPP COMMANDS FINISHED SUCCESSFULLY ##########

########## ARCHIVE COMMANDS ##########

[Fri Nov 11 18:11:39 2011] INFO: No commands defined

########## ARCHIVE COMMANDS FINISHED SUCCESSFULLY ##########

########## NetApp Snap Creator Framework finished successfully ##########

[Fri Nov 11 18:11:39 2011] INFO: INFO: NetApp Snap Creator Framework finished successfully ( Action: snap )

[Fri Nov 11 18:11:39 2011] INFO: Creating OM Event (script:information-event) on orahost1.netapp.com

[Fri Nov 11 18:11:39 2011] INFO: OM Event (script:information-event) on orahost1.netapp.com created successfully

[root@orahost1 ntap]#

List of snapshots taken on primary storage after the test backup is triggered:

[root@orahost1 ntap]# snapcreator --action snaplist --profile ntap -config ntap_full_01

########## NetApp Snap Creator Framework Snapshot (Primary) List for ontap-802-src.netapp.com:v_oractl_01 #########

### Snapshot Name ### ### Snapshot Timestamp ###

snapcreator_ntap_full_01-hourly_20111111111926 Nov 11 2011 11:19:37

snapcreator_ntap_full_01-hourly_20111111124057 Nov 11 2011 12:41:05

snapcreator_ntap_full_01-hourly_20111111130000 Nov 11 2011 13:00:11

snapcreator_ntap_full_01-hourly_20111111140000 Nov 11 2011 14:00:16

snapcreator_ntap_full_01-hourly_20111111150000 Nov 11 2011 15:00:17

snapcreator_ntap_full_01-hourly_20111111160000 Nov 11 2011 16:00:16

snapcreator_ntap_full_01-hourly_20111111170000 Nov 11 2011 17:00:13

snapcreator_ntap_full_01-hourly_20111111180655 Nov 11 2011 18:07:00 -> new backup