SC 4.0.0C - Windows mysql Plugin Problem

vMarkus_K · ‎2013-02-20

Hi,

my configuration looks like this:

CONFIG_TYPE=STANDARD

LOG_NUM=30

SNAPDRIVE=Y

SNAPDRIVE_DISCOVERY=N

LOG_TRACE_ENABLE=N

USE_PROXY=N

NTAP_PWD_PROTECTION=Y

NTAP_TIMEOUT=60

META_DATA_VOLUME=

USE_GLOBAL_CONFIG=N

VOLUMES=nes-san-04.rsknes.int:vol_qmm_01

FEDERATED_APPLICATIONS=

ALLOW_IP_ADDR=N

SC_TMP_DIR=

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

# Connection Options #

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

NTAP_USERS=nes-san-04.rsknes.int:root/4d2b48385330704a672f6447744937565348425562773d3d0a

MANAGEMENT_INTERFACES=

PORT=443

TRANSPORT=HTTPS

SECONDARY_INTERFACES=

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

# CMode Options #

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

CMODE_CLUSTER_NAME=

CMODE_CLUSTER_USERS=

CMODE_SNAPSHOT_FORCE_DELETE=Y

CMODE_SET=N

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

# Snapshot Options #

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

SNAME=mysql

SNAP_TIMESTAMP_ONLY=N

NTAP_USE_EXTERNAL_SNAPSHOT=N

NTAP_SNAPSHOT_NODELETE=N

NTAP_CONSISTENCY_GROUP_TIMEOUT=MEDIUM

NTAP_SNAPSHOT_RETENTIONS=daily:5,hourly:8

NTAP_SNAPSHOT_CREATE_CMD01="c:/Program Files/NetApp/SnapDrive/sdcli" snap create -s %SNAME-%SNAP_TYPE_recent -D E:

NTAP_CONSISTENCY_GROUP_WAFL_SYNC=N

NTAP_CONSISTENCY_GROUP_SNAPSHOT=N

NTAP_SNAPSHOT_RETENTION_AGE=

NTAP_METADATA_SNAPSHOT_CREATE_CMD=

NTAP_SNAPSHOT_DELETE_BY_AGE_ONLY=N

NTAP_SNAPSHOT_DEPENDENCY_IGNORE=N

NTAP_SNAPSHOT_RESTORE_AUTO_DETECT=N

NTAP_SNAPSHOT_DISABLE=N

NTAP_EXTERNAL_SNAPSHOT_REGEX=.*

NTAP_SNAPSHOT_CLEANUP=N

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

# SnapVault Options #

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

NTAP_SNAPVAULT_UPDATE=N

NTAP_SNAPVAULT_NODELETE=N

SNAPVAULT_QTREE_INCLUDE=

NTAP_SNAPVAULT_RESTORE_WAIT=N

NTAP_SNAPVAULT_RETENTION_AGE=

NTAP_SNAPVAULT_SNAPSHOT=N

NTAP_SNAPVAULT_MAX_TRANSFER=

NTAP_SNAPVAULT_RETENTIONS=

NTAP_SNAPVAULT_WAIT=0

SNAPVAULT_VOLUMES=

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

# SnapMirror Options #

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

NTAP_SNAPMIRROR_WAIT=60

NTAP_SNAPMIRROR_USE_SNAPSHOT=N

NTAP_SNAPMIRROR_MAX_TRANSFER=

SNAPMIRROR_VOLUMES=

SNAPMIRROR_CASCADING_VOLUMES=

NTAP_SNAPMIRROR_CASCADING_UPDATE=N

NTAP_SNAPMIRROR_UPDATE=N

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

# Clone Options #

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

NTAP_CLONE_IGROUP_MAP=

NTAP_NFS_EXPORT_ACCESS=read-only

NTAP_LUN_CLONE_RESERVATION=N

NTAP_CLONE_SECONDARY_VOLUMES=

NTAP_NUM_VOL_CLONES=1

NTAP_CLONE_FOR_BACKUP=N

NTAP_NFS_EXPORT_PERSISTENT=N

NTAP_CIFS_EXPORT_ENABLE=N

NTAP_CLONE_SECONDARY=N

NTAP_NFS_EXPORT_HOST=

NTAP_VOL_CLONE_RESERVE=NONE

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

# ProtectionManager Options #

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

NTAP_DFM_DATA_SET=

NTAP_PM_RUN_BACKUP=N

NTAP_PM_UPDATE=N

NTAP_DFM_SNAPSHOT_FORMAT=

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

# OperationsManager Options #

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

OM_TRANSPORT=HTTP

OM_HOST=

OM_EVENT_GENERATE=N

OM_USER=

OM_PWD=

OM_PORT=8488

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

# OSSV Options #

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

NTAP_OSSV_FS_SNAPSHOT=

NTAP_OSSV_FS_SNAPSHOT_CREATE_CMD01=

NTAP_OSSV_HOMEDIR=

NTAP_OSSV_ENABLE=N

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

# APP Commands #

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

UMOUNT_CMD01=

ARCHIVE_CMD01=

APP_UNQUIESCE_CMD01=

MOUNT_CMD01=

APP_QUIESCE_CMD01=

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

# Pre Commands #

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

PRE_CLONE_CREATE_CMD01=

PRE_RESTORE_CMD01=

PRE_EXIT_CMD01=

PRE_NTAP_CMD01=

PRE_APP_UNQUIESCE_CMD01=

PRE_APP_QUIESCE_CMD01=

PRE_NTAP_CLONE_DELETE_CMD01=

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

# Post Commands #

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

POST_NTAP_DATA_TRANSFER_CMD01=

POST_RESTORE_CMD01=

POST_APP_QUIESCE_CMD01=

POST_NTAP_CMD01=

POST_CLONE_CREATE_CMD01=

POST_APP_UNQUIESCE_CMD01=

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

# Event Options #

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

SUCCESS_MSG=INFO: NetApp Snap Creator Framework finished successfully (Action: %ACTION)

NTAP_ASUP_ERROR_ENABLE=N

SENDTRAP=

SUCCESS_TRAP=

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

# Agent Options #

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

SC_AGENT_UNQUIESCE_TIMEOUT=1805

SC_AGENT_WATCHDOG_ENABLE=N

SC_AGENT=nes-qmm-01.rsknes.int:9090

SC_AGENT_LOG_ENABLE=Y

SC_AGENT_TIMEOUT=1800

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

# Clone Target Options #

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

SC_CLONE_TARGET=

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

# Application Options #

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

APP_NAME=mysql

APP_IGNORE_ERROR=N

APP_CONF_PERSISTENCE=Y

APP_AUTO_DISCOVERY=N

APP_DEFINED_RESTORE=N

APP_DEFINED_CLONE=N

APP_DEFINED_BACKUP=N

APP_DEFINED_UMOUNT=N

FS_NAME=

APP_DEFINED_MOUNT=N

VALIDATE_VOLUMES=

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

# Archive Options #

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

ARCHIVE_LOG_RECURSIVE_SEARCH=N

ARCHIVE_LOG_DIR=

ARCHIVE_LOG_EXT=

ARCHIVE_LOG_RETENTION=

ARCHIVE_LOG_ENABLE=

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

# Plug-In Parameter #

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

PORTS=infoboard_nes:3306;information_schema:3306;mysql:3306;phpmyadmin:3306;performance_schema:3306

HOST=localhost

MASTER_SLAVE=N

MYSQL_DATABASES=infoboard_nes:root/477250627a5444634d42513d0a;information_schema:root/477250627a5444634d42513d0a;mysql:root/477250627a5444634d42513d0a;phpmyadmin:root/477250627a5444634d42513d0a;performance_schema:root/477250627a5444634d42513d0a

The First Backup Jobs works great.

Agent LOG:

[Wed Feb 20 15:34:30 2013] DEBUG: mysql::setENV finished successfully

[Wed Feb 20 15:34:30 2013] INFO: Quiescing databases

[Wed Feb 20 15:34:30 2013] INFO: Quiescing database infoboard_nes

[Wed Feb 20 15:34:30 2013] DEBUG: Connection to infoboard_nes successfully established

[Wed Feb 20 15:34:30 2013] DEBUG: Executing sql command 'flush tables with read lock' for database infoboard_nes

[Wed Feb 20 15:34:30 2013] DEBUG: Executing sql command 'flush logs' for database infoboard_nes

[Wed Feb 20 15:34:30 2013] INFO: Quiescing database infoboard_nes finished successfully

[Wed Feb 20 15:34:30 2013] INFO: Quiescing database mysql

[Wed Feb 20 15:34:30 2013] DEBUG: Connection to mysql successfully established

[Wed Feb 20 15:34:30 2013] DEBUG: Executing sql command 'flush tables with read lock' for database mysql

[Wed Feb 20 15:34:30 2013] DEBUG: Executing sql command 'flush logs' for database mysql

[Wed Feb 20 15:34:30 2013] INFO: Quiescing database mysql finished successfully

[Wed Feb 20 15:34:30 2013] INFO: Quiescing database performance_schema

[Wed Feb 20 15:34:30 2013] DEBUG: Connection to performance_schema successfully established

[Wed Feb 20 15:34:30 2013] DEBUG: Executing sql command 'flush tables with read lock' for database performance_schema

[Wed Feb 20 15:34:30 2013] DEBUG: Executing sql command 'flush logs' for database performance_schema

[Wed Feb 20 15:34:30 2013] INFO: Quiescing database performance_schema finished successfully

[Wed Feb 20 15:34:30 2013] INFO: Quiescing database information_schema

[Wed Feb 20 15:34:30 2013] DEBUG: Connection to information_schema successfully established

[Wed Feb 20 15:34:30 2013] DEBUG: Executing sql command 'flush tables with read lock' for database information_schema

[Wed Feb 20 15:34:30 2013] DEBUG: Executing sql command 'flush logs' for database information_schema

[Wed Feb 20 15:34:30 2013] INFO: Quiescing database information_schema finished successfully

[Wed Feb 20 15:34:30 2013] INFO: Quiescing database phpmyadmin

[Wed Feb 20 15:34:30 2013] DEBUG: Connection to phpmyadmin successfully established

[Wed Feb 20 15:34:30 2013] DEBUG: Executing sql command 'flush tables with read lock' for database phpmyadmin

[Wed Feb 20 15:34:30 2013] DEBUG: Executing sql command 'flush logs' for database phpmyadmin

[Wed Feb 20 15:34:30 2013] INFO: Quiescing database phpmyadmin finished successfully

[Wed Feb 20 15:34:30 2013] INFO: Quiescing databases finished successfully

[Wed Feb 20 15:34:36 2013] DEBUG: mysql::setENV finished successfully

[Wed Feb 20 15:34:36 2013] INFO: Unquiescing databases

[Wed Feb 20 15:34:36 2013] INFO: Unquiescing database infoboard_nes

[Wed Feb 20 15:34:36 2013] DEBUG: Connection to infoboard_nes established successfully

[Wed Feb 20 15:34:36 2013] DEBUG: Executing sql command 'unlock tables' for database infoboard_nes

[Wed Feb 20 15:34:36 2013] DEBUG: Disconnecting from database infoboard_nes

[Wed Feb 20 15:34:36 2013] INFO: Unquiescing database infoboard_nes finished successfully

[Wed Feb 20 15:34:36 2013] INFO: Unquiescing database mysql

[Wed Feb 20 15:34:36 2013] DEBUG: Connection to mysql established successfully

[Wed Feb 20 15:34:36 2013] DEBUG: Executing sql command 'unlock tables' for database mysql

[Wed Feb 20 15:34:36 2013] DEBUG: Disconnecting from database mysql

[Wed Feb 20 15:34:36 2013] INFO: Unquiescing database mysql finished successfully

[Wed Feb 20 15:34:36 2013] INFO: Unquiescing database performance_schema

[Wed Feb 20 15:34:36 2013] DEBUG: Connection to performance_schema established successfully

[Wed Feb 20 15:34:36 2013] DEBUG: Executing sql command 'unlock tables' for database performance_schema

[Wed Feb 20 15:34:36 2013] DEBUG: Disconnecting from database performance_schema

[Wed Feb 20 15:34:36 2013] INFO: Unquiescing database performance_schema finished successfully

[Wed Feb 20 15:34:36 2013] INFO: Unquiescing database information_schema

[Wed Feb 20 15:34:36 2013] DEBUG: Connection to information_schema established successfully

[Wed Feb 20 15:34:36 2013] DEBUG: Executing sql command 'unlock tables' for database information_schema

[Wed Feb 20 15:34:36 2013] DEBUG: Disconnecting from database information_schema

[Wed Feb 20 15:34:36 2013] INFO: Unquiescing database information_schema finished successfully

[Wed Feb 20 15:34:36 2013] INFO: Unquiescing database phpmyadmin

[Wed Feb 20 15:34:36 2013] DEBUG: Connection to phpmyadmin established successfully

[Wed Feb 20 15:34:36 2013] DEBUG: Executing sql command 'unlock tables' for database phpmyadmin

[Wed Feb 20 15:34:36 2013] DEBUG: Disconnecting from database phpmyadmin

[Wed Feb 20 15:34:36 2013] INFO: Unquiescing database phpmyadmin finished successfully

[Wed Feb 20 15:34:36 2013] INFO: Unquiescing databases finished successfully

Job Log:

########## Detecting Data ONTAP mode for nes-san-04.rsknes.int ##########

[2013-02-20 15:34:29,327] INFO: STORAGE-03031: System version details of [nes-san-04.rsknes.int].

[2013-02-20 15:34:29,327] DEBUG: <system-get-version/>

[2013-02-20 15:34:29,327] DEBUG: <system-get-ontapi-version/>

[2013-02-20 15:34:29,327] INFO: STORAGE-03032: System version details of [nes-san-04.rsknes.int] finished successfully.

########## Agent validation ##########

[2013-02-20 15:34:29,592] INFO: Agent validation completed successfuly for agent nes-qmm-01.rsknes.int:9090

########## Plugin validation ##########

[2013-02-20 15:34:29,592] INFO: Plugin validation completed successfuly for plugin mysql

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

[2013-02-20 15:34:29,608] INFO: Pre application quiesce commands are not defined

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

[2013-02-20 15:34:29,608] INFO: Application auto discovery is not enabled skipping .

[2013-02-20 15:34:29,608] INFO: Validate volume is not enabled skipping validate volume task.

########## Application Quiesce ##########

[2013-02-20 15:34:29,889] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] mysql::setENV finished successfully

[2013-02-20 15:34:29,889] INFO: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Quiescing databases

[2013-02-20 15:34:29,889] INFO: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Quiescing database infoboard_nes

[2013-02-20 15:34:29,889] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Connection to infoboard_nes successfully established

[2013-02-20 15:34:29,889] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Executing sql command 'flush tables with read lock' for database infoboard_nes

[2013-02-20 15:34:29,889] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Executing sql command 'flush logs' for database infoboard_nes

[2013-02-20 15:34:29,889] INFO: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Quiescing database infoboard_nes finished successfully

[2013-02-20 15:34:29,889] INFO: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Quiescing database mysql

[2013-02-20 15:34:29,889] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Connection to mysql successfully established

[2013-02-20 15:34:29,889] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Executing sql command 'flush tables with read lock' for database mysql

[2013-02-20 15:34:29,889] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Executing sql command 'flush logs' for database mysql

[2013-02-20 15:34:29,889] INFO: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Quiescing database mysql finished successfully

[2013-02-20 15:34:29,889] INFO: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Quiescing database performance_schema

[2013-02-20 15:34:29,889] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Connection to performance_schema successfully established

[2013-02-20 15:34:29,889] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Executing sql command 'flush tables with read lock' for database performance_schema

[2013-02-20 15:34:29,889] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Executing sql command 'flush logs' for database performance_schema

[2013-02-20 15:34:29,889] INFO: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Quiescing database performance_schema finished successfully

[2013-02-20 15:34:29,889] INFO: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Quiescing database information_schema

[2013-02-20 15:34:29,889] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Connection to information_schema successfully established

[2013-02-20 15:34:29,889] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Executing sql command 'flush tables with read lock' for database information_schema

[2013-02-20 15:34:29,889] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Executing sql command 'flush logs' for database information_schema

[2013-02-20 15:34:29,889] INFO: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Quiescing database information_schema finished successfully

[2013-02-20 15:34:29,889] INFO: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Quiescing database phpmyadmin

[2013-02-20 15:34:29,889] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Connection to phpmyadmin successfully established

[2013-02-20 15:34:29,889] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Executing sql command 'flush tables with read lock' for database phpmyadmin

[2013-02-20 15:34:29,889] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Executing sql command 'flush logs' for database phpmyadmin

[2013-02-20 15:34:29,889] INFO: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Quiescing database phpmyadmin finished successfully

[2013-02-20 15:34:29,889] INFO: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Quiescing databases finished successfully

########## Application Quiesce finished successfully ##########

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

[2013-02-20 15:34:29,889] INFO: Post application quiesce commands are not defined

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

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

[2013-02-20 15:34:29,889] INFO: Pre netapp commands are not defined

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

########## Generating Info ASUP on nes-san-04.rsknes.int ##########

[2013-02-20 15:34:30,186] INFO: STORAGE-01001: Creating autosupport message with event id [0], category [Backup Started], description [INFO: Snap Creator Community Release 4.0.0c Backup for mysql ACTION: backup POLICY: hourly Plugin: mysql Supported Volumes: vol_qmm_01, Started], level [INFO], hostname [nes-prn-01 [nes-qmm-01.rsknes.int:9090]].

[2013-02-20 15:34:30,186] DEBUG: <ems-autosupport-log>

<computer-name>nes-prn-01 [nes-qmm-01.rsknes.int:9090]</computer-name>

<event-id>0</event-id>

<event-source>SNAPCREATOR</event-source>

<app-version>Snap Creator Community Release 4.0.0c</app-version>

<category>Backup Started</category>

<event-description>INFO: Snap Creator Community Release 4.0.0c Backup for mysql ACTION: backup POLICY: hourly Plugin: mysql Supported Volumes: vol_qmm_01, Started</event-description>

<log-level>6</log-level>

<auto-support>false</auto-support>

</ems-autosupport-log>

[2013-02-20 15:34:30,186] INFO: STORAGE-01002: Creating autosupport message with event id [0], category [Backup Started], description [INFO: Snap Creator Community Release 4.0.0c Backup for mysql ACTION: backup POLICY: hourly Plugin: mysql Supported Volumes: vol_qmm_01, Started], level [INFO], hostname [nes-prn-01 [nes-qmm-01.rsknes.int:9090]] finished successfully.

[2013-02-20 15:34:30,186] INFO: ASUP finished successfully on nes-san-04.rsknes.int

########## Running NetApp Snapshot copy Rename on Primary devices ##########

[2013-02-20 15:34:30,186] DEBUG: Performing snaplist operation on nes-san-04.rsknes.int:vol_qmm_01

[2013-02-20 15:34:30,499] INFO: STORAGE-02090: Listing Snapshot copies on volume [vol_qmm_01].

[2013-02-20 15:34:30,499] DEBUG: <snapshot-list-info>

</snapshot-list-info>

[2013-02-20 15:34:30,499] INFO: STORAGE-02091: Listing Snapshot copies on volume [vol_qmm_01] finished successfully.

[2013-02-20 15:34:30,499] INFO: Rename the recent Snapshot copy from mysql-hourly_recent to mysql-hourly_20130220153430 for vol_qmm_01

[2013-02-20 15:34:31,405] INFO: STORAGE-02100: Renaming snapshot [mysql-hourly_recent] on volume [vol_qmm_01] to [mysql-hourly_20130220153430].

[2013-02-20 15:34:31,405] DEBUG: <snapshot-rename>

<current-name>mysql-hourly_recent</current-name>

<new-name>mysql-hourly_20130220153430</new-name>

</snapshot-rename>

[2013-02-20 15:34:31,405] INFO: STORAGE-02101: Renaming Snapshot copy [mysql-hourly_recent] on volume [vol_qmm_01] to [mysql-hourly_20130220153430] finished successfully.

[2013-02-20 15:34:31,405] INFO: Snapshot copy rename finished successfully

########## Snapshot copy Rename finished successfully ! ##########

########## File system plug-in not defined. Skipping file system quiesce ##########

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

[2013-02-20 15:34:35,733] INFO: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Executing Snapshot create command ["c:/Program Files/NetApp/SnapDrive/sdcli" snap create -s mysql-hourly_recent -D E:] on nes-qmm-01.rsknes.int

[2013-02-20 15:34:35,733] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Executing command ["c:/Program Files/NetApp/SnapDrive/sdcli" snap create -s mysql-hourly_recent -D E:]

[2013-02-20 15:34:35,733] TRACE: Command ["c:/Program Files/NetApp/SnapDrive/sdcli" snap create -s mysql-hourly_recent -D E:] finished with

exit code: [0]

stdout: [Initializing...NES-QMM-01 : Checking policies

NES-QMM-01 : Checking access control

NES-QMM-01 : Preparing LUNs for Snapshot creation

NES-QMM-01 : Ready to create snapshot copy

NES-QMM-01 : Creating a Snapshot for the LUN

NES-QMM-01 : Initiating snapmirror update for any source volumes.

The operation completed successfully.

]

stderr: []

[2013-02-20 15:34:35,733] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Command ["c:/Program Files/NetApp/SnapDrive/sdcli" snap create -s mysql-hourly_recent -D E:] finished successfully with message

[Initializing...NES-QMM-01 : Checking policies

NES-QMM-01 : Checking access control

NES-QMM-01 : Preparing LUNs for Snapshot creation

NES-QMM-01 : Ready to create snapshot copy

NES-QMM-01 : Creating a Snapshot for the LUN

NES-QMM-01 : Initiating snapmirror update for any source volumes.

The operation completed successfully.

]

[2013-02-20 15:34:35,733] INFO: Snapshot create completed successfully

########## Snapshot copy create commands finished successfully ##########

[2013-02-20 15:34:35,733] INFO: Using command to create the Snapshot copy

[2013-02-20 15:34:35,733] INFO: Skipping SIS clone backup.

[2013-02-20 15:34:35,733] INFO: Using command to create the Snapshot copy

[2013-02-20 15:34:35,733] INFO: Skipping consistency group Snapshot copy

[2013-02-20 15:34:35,733] INFO: Using command to create the Snapshot copy

[2013-02-20 15:34:35,733] INFO: Skipping snapshot creation using ZAPI.

########## File system plug-in not defined. Skipping file system unquiesce ##########

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

[2013-02-20 15:34:35,733] INFO: Pre application unquiesce commands are not defined

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

########## Application Unquiesce ##########

[2013-02-20 15:34:36,014] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] mysql::setENV finished successfully

[2013-02-20 15:34:36,014] INFO: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Unquiescing databases

[2013-02-20 15:34:36,014] INFO: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Unquiescing database infoboard_nes

[2013-02-20 15:34:36,014] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Connection to infoboard_nes established successfully

[2013-02-20 15:34:36,014] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Executing sql command 'unlock tables' for database infoboard_nes

[2013-02-20 15:34:36,014] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Disconnecting from database infoboard_nes

[2013-02-20 15:34:36,014] INFO: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Unquiescing database infoboard_nes finished successfully

[2013-02-20 15:34:36,014] INFO: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Unquiescing database mysql

[2013-02-20 15:34:36,014] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Connection to mysql established successfully

[2013-02-20 15:34:36,014] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Executing sql command 'unlock tables' for database mysql

[2013-02-20 15:34:36,014] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Disconnecting from database mysql

[2013-02-20 15:34:36,014] INFO: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Unquiescing database mysql finished successfully

[2013-02-20 15:34:36,014] INFO: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Unquiescing database performance_schema

[2013-02-20 15:34:36,014] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Connection to performance_schema established successfully

[2013-02-20 15:34:36,014] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Executing sql command 'unlock tables' for database performance_schema

[2013-02-20 15:34:36,014] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Disconnecting from database performance_schema

[2013-02-20 15:34:36,014] INFO: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Unquiescing database performance_schema finished successfully

[2013-02-20 15:34:36,014] INFO: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Unquiescing database information_schema

[2013-02-20 15:34:36,014] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Connection to information_schema established successfully

[2013-02-20 15:34:36,014] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Executing sql command 'unlock tables' for database information_schema

[2013-02-20 15:34:36,014] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Disconnecting from database information_schema

[2013-02-20 15:34:36,014] INFO: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Unquiescing database information_schema finished successfully

[2013-02-20 15:34:36,014] INFO: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Unquiescing database phpmyadmin

[2013-02-20 15:34:36,014] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Connection to phpmyadmin established successfully

[2013-02-20 15:34:36,014] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Executing sql command 'unlock tables' for database phpmyadmin

[2013-02-20 15:34:36,014] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Disconnecting from database phpmyadmin

[2013-02-20 15:34:36,014] INFO: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Unquiescing database phpmyadmin finished successfully

[2013-02-20 15:34:36,014] INFO: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] Unquiescing databases finished successfully

########## Application Unquiesce finished successfully ##########

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

[2013-02-20 15:34:36,014] INFO: Post application unquiesce commands are not defined

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

########## Generating Info ASUP on nes-san-04.rsknes.int ##########

[2013-02-20 15:34:36,327] INFO: STORAGE-01001: Creating autosupport message with event id [0], category [Backup Completed], description [INFO: Snap Creator Community Release 4.0.0c Backup for mysql ACTION: backup POLICY: hourly Plugin: mysql Supported Volumes: vol_qmm_01, finished], level [INFO], hostname [nes-prn-01 [nes-qmm-01.rsknes.int:9090]].

[2013-02-20 15:34:36,327] DEBUG: <ems-autosupport-log>

<computer-name>nes-prn-01 [nes-qmm-01.rsknes.int:9090]</computer-name>

<event-id>0</event-id>

<event-source>SNAPCREATOR</event-source>

<app-version>Snap Creator Community Release 4.0.0c</app-version>

<category>Backup Completed</category>

<event-description>INFO: Snap Creator Community Release 4.0.0c Backup for mysql ACTION: backup POLICY: hourly Plugin: mysql Supported Volumes: vol_qmm_01, finished</event-description>

<log-level>6</log-level>

<auto-support>false</auto-support>

</ems-autosupport-log>

[2013-02-20 15:34:36,327] INFO: STORAGE-01002: Creating autosupport message with event id [0], category [Backup Completed], description [INFO: Snap Creator Community Release 4.0.0c Backup for mysql ACTION: backup POLICY: hourly Plugin: mysql Supported Volumes: vol_qmm_01, finished], level [INFO], hostname [nes-prn-01 [nes-qmm-01.rsknes.int:9090]] finished successfully.

[2013-02-20 15:34:36,327] INFO: ASUP finished successfully on nes-san-04.rsknes.int

[2013-02-20 15:34:36,327] WARN: Configuration not enabled for snapvault!

########## Running NetApp Snapshot copy Rename on Secondary devices ##########

[2013-02-20 15:34:36,327] WARN: Configuration not enabled for snapvault!

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

[2013-02-20 15:34:36,327] INFO: No commands defined

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

########## Running Snapshot copy Delete on Primary ##########

[2013-02-20 15:34:36,702] INFO: STORAGE-02090: Listing Snapshot copies on volume [vol_qmm_01].

[2013-02-20 15:34:36,702] DEBUG: <snapshot-list-info>

</snapshot-list-info>

[2013-02-20 15:34:36,702] INFO: STORAGE-02091: Listing Snapshot copies on volume [vol_qmm_01] finished successfully.

########## POST COMMANDS ##########

[2013-02-20 15:34:36,702] INFO: No commands defined

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

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

[2013-02-20 15:34:36,702] INFO: Archive commands are not defined

########## Snap Creator Community Release 4.0.0c finished successfully ##########

[2013-02-20 15:34:36,717] INFO: INFO: NetApp Snap Creator Framework finished successfully (Action: backup)

The Next backup fails with the following LOG:

Agent LOG:

[Wed Feb 20 15:36:01 2013] DEBUG: mysql::setENV finished successfully

[Wed Feb 20 15:36:01 2013] INFO: Quiescing databases

[Wed Feb 20 15:36:01 2013] INFO: Quiescing database infoboard_nes

[Wed Feb 20 15:36:01 2013] DEBUG: Connection to infoboard_nes successfully established

[Wed Feb 20 15:36:01 2013] DEBUG: Executing sql command 'flush tables with read lock' for database infoboard_nes

[Wed Feb 20 15:36:01 2013] DEBUG: Executing sql command 'flush logs' for database infoboard_nes

[Wed Feb 20 15:36:01 2013] INFO: Quiescing database infoboard_nes finished successfully

[Wed Feb 20 15:36:01 2013] INFO: Quiescing database mysql

[Wed Feb 20 15:36:01 2013] DEBUG: Connection to mysql successfully established

[Wed Feb 20 15:36:01 2013] DEBUG: Executing sql command 'flush tables with read lock' for database mysql

[Wed Feb 20 15:36:01 2013] ERROR: [agt-00013] send: Cannot determine peer address at /<C:\Program Files\NetApp\Snap_Creator_Framework\scAgent4.0.0c\snapcreator.exe>Net/MySQL.pm line 293

[Wed Feb 20 15:36:01 2013] DEBUG: mysql::setENV finished successfully

[Wed Feb 20 15:36:01 2013] INFO: Unquiescing databases

[Wed Feb 20 15:36:01 2013] INFO: Unquiescing database infoboard_nes

[Wed Feb 20 15:36:01 2013] DEBUG: Connection to infoboard_nes established successfully

[Wed Feb 20 15:36:01 2013] DEBUG: Executing sql command 'unlock tables' for database infoboard_nes

[Wed Feb 20 15:36:01 2013] DEBUG: Disconnecting from database infoboard_nes

[Wed Feb 20 15:36:01 2013] INFO: Unquiescing database infoboard_nes finished successfully

[Wed Feb 20 15:36:01 2013] INFO: Unquiescing database mysql

[Wed Feb 20 15:36:01 2013] DEBUG: Connection to mysql established successfully

[Wed Feb 20 15:36:01 2013] DEBUG: Executing sql command 'unlock tables' for database mysql

[Wed Feb 20 15:36:01 2013] ERROR: [agt-00013] send: Cannot determine peer address at /<C:\Program Files\NetApp\Snap_Creator_Framework\scAgent4.0.0c\snapcreator.exe>Net/MySQL.pm line 293

Job LOG:

########## Detecting Data ONTAP mode for nes-san-04.rsknes.int ##########

[2013-02-20 15:36:00,467] INFO: STORAGE-03031: System version details of [nes-san-04.rsknes.int].

[2013-02-20 15:36:00,467] DEBUG: <system-get-version/>

[2013-02-20 15:36:00,467] DEBUG: <system-get-ontapi-version/>

[2013-02-20 15:36:00,467] INFO: STORAGE-03032: System version details of [nes-san-04.rsknes.int] finished successfully.

########## Agent validation ##########

[2013-02-20 15:36:00,702] INFO: Agent validation completed successfuly for agent nes-qmm-01.rsknes.int:9090

########## Plugin validation ##########

[2013-02-20 15:36:00,717] INFO: Plugin validation completed successfuly for plugin mysql

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

[2013-02-20 15:36:00,717] INFO: Pre application quiesce commands are not defined

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

[2013-02-20 15:36:00,717] INFO: Application auto discovery is not enabled skipping .

[2013-02-20 15:36:00,717] INFO: Validate volume is not enabled skipping validate volume task.

########## Application Quiesce ##########

[2013-02-20 15:36:00,983] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] mysql::setENV finished successfully

[2013-02-20 15:36:00,983] ERROR: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] [agt-00013] send: Cannot determine peer address at /<C:\Program Files\NetApp\Snap_Creator_Framework\scAgent4.0.0c\snapcreator.exe>Net/MySQL.pm line 293

[2013-02-20 15:36:00,983] ERROR: [nes-qmm-01.rsknes.int:9090(4.0.0.1)] SCF-00037: Application quiesce for plugin [mysql] failed with error [send: Cannot determine peer address at /<C:\Program Files\NetApp\Snap_Creator_Framework\scAgent4.0.0c\snapcreator.exe>Net/MySQL.pm line 293

] and exit code [1], Exiting!

########## Application Unquiesce ##########

[2013-02-20 15:36:01,202] DEBUG: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] mysql::setENV finished successfully

[2013-02-20 15:36:01,202] ERROR: [nes-qmm-01.rsknes.int:9090 (4.0.0.1)] [agt-00013] send: Cannot determine peer address at /<C:\Program Files\NetApp\Snap_Creator_Framework\scAgent4.0.0c\snapcreator.exe>Net/MySQL.pm line 293

[2013-02-20 15:36:01,202] ERROR: [nes-qmm-01.rsknes.int:9090(4.0.0.1)] SCF-00032: Application unquiesce failed due to application error. Check logs and application settings. To ignore application errors and proceed with backup you can set APP_IGNORE_ERROR=Y.

When I restart the SnapCreator Agent on The mysql system, the Job works great Again.

Any Ideas??

nkarthik · ‎2013-04-02

Try the following:

1. reinstall net::mysql and try again.

2. Try with Snapdrive

Regards,

karthikeyan.N

SC 4.0.0C - Windows mysql Plugin Problem

Get ready to power on