Data Backup and Recovery

Snap Creator 4.1 MySQL plugin quiesce operation fails

EEntressangle
Hello,
 
using snapcreator 4.1.2, I'm trying to perform a backup of a mysql db hosted on a primary NAS, using mysql plugin. A snapmirror is also configured from primary NAS nas40-ctrl2 to backup NAS nas-ctrl2-LMG16.
Everything seems to be fine except the mysql "quiesce" which fails.
 
SCF-00038: Application quiesce for plug-in [mysql] failed with exit code [102]
How can I investigate this issue ?
 
Traces follow, thanks
 
Regards
 
2
Config is attached to policy object
3
Validating policy: SnapMirrorPolicy finished successfully
4
########## Detecting Data ONTAP mode for nas40-ctrl2 ##########
5
STORAGE-03031: Getting system version details of [nas40-ctrl2]
6
STORAGE-03032: Getting system version details of [nas40-ctrl2] finished successfully.
7
########## Agent validation ##########
8
Agent validation completed successfully for agent 10.35.84.19:9090
9
########## Plugin validation ##########
10
Plugin validation completed successfully for plugin mysql
11
Application auto discovery is not enabled skipping .
12
########## Running storage discovery ##########
13
STORAGE-02073: Retrieving SnapMirror relationships
14
STORAGE-02074: Retrieving SnapMirror relationships on controller [nas40-ctrl2] finished successfully
15
STORAGE-02070: Retrieving SnapMirror status
16
STORAGE-02071: Retrieving SnapMirror status on controller [NAS-ctrl2-LMG16] successful
17
STORAGE-02090: Listing Snapshot copies on volume [vol_db_data].
18
STORAGE-02091: Listing Snapshot copies on volume [vol_db_data] finished successfully.
19
########## Storage discovery finished successfully ! ##########
20
########## Pre Application Quiesce commands ##########
21
Pre application quiesce commands are not defined
22
Pre Application Quiesce commands finished successfully
23
Validate volume is not enabled skipping validate volume task.
24
########## Application Quiesce ##########
25
Application Quiesce for plugin : mysql
26
[10.35.84.19:9090 (4.1.1.1)] Operation failed. Reason: The watchdog killed the running operation. Verify that plugins/wrapper/wrapper binary has execute permission set. Increase the WRAPPER_TIMEOUT_IN_MSEC value in agent.properties if operations require more time to complete.
27
[10.35.84.19:9090(4.1.1.1)] SCF-00038: Application quiesce for plug-in [mysql] failed with exit code [102], continuing with backup.
28
Application quiesce result is empty  from plugin mysql. skipping config update operation
29
Application Quiesce for plugin : mysql finished successfully
30
########## Application Quiesce finished successfully ##########
31
########## POST APPLICATION QUIESCE COMMANDS ##########
32
Post application quiesce commands are not defined
33
########## POST APPLICATION QUIESCE COMMANDS FINISHED SUCCESSFULLY  ##########
34
########## Pre NTAP commands ##########
35
Pre NTAP commands are not defined
36
Pre NTAP commands finished successfully
37
########## Generating Info ASUP on nas40-ctrl2 ##########
38
STORAGE-01001: Creating AutoSupport message with event id [0], category [Backup Started], description [INFO: Snap Creator Framework 4.1.2 Backup for titisnapshot ACTION: backup POLICY: SnapMirrorPolicy Plugin: mysql [Supported] Volumes: vol_db_data, Started], level [INFO], hostname [LMG40MDFOAM2 [10.35.84.19:9090]]
39
STORAGE-01002: Creating AutoSupport message with event id [0], category [Backup Started], description [INFO: Snap Creator Framework 4.1.2 Backup for titisnapshot ACTION: backup POLICY: SnapMirrorPolicy Plugin: mysql [Supported] Volumes: vol_db_data, Started], level [INFO], hostname [LMG40MDFOAM2 [10.35.84.19:9090]] successful
40
ASUP finished successfully on nas40-ctrl2
41
########## Running NetApp Snapshot copy Rename on Primary devices ##########
42
########## Running NetApp Snapshot copy Rename on Secondary devices ##########
43
########## File system plug-in not defined. Skipping file system quiesce ##########
44
########## SNAPSHOT CREATE COMMANDS ##########
45
########## Snapshot copy create commands finished successfully ##########
46
########## Taking Snapshot copy on Primary nas40-ctrl2:vol_db_data ##########
47
STORAGE-02007: Creating Snapshot copy [titisnapshot-SnapMirrorPolicy_20151015173001] on volume [vol_db_data]
48
STORAGE-02008: Snapshot copy [titisnapshot-SnapMirrorPolicy_20151015173001] on volume [vol_db_data] created successfully
49
Snapshot copy create of titisnapshot-SnapMirrorPolicy_20151015173001 on nas40-ctrl2:vol_db_data Completed Successfully
50
########## File system plug-in not defined. Skipping file system unquiesce ##########
51
########## Pre Application Unquiesce commands ##########
52
Pre Application Unquiesce commands are not defined
53
Pre Application Unquiesce commands finished successfully 
54
########## Application Unquiesce ##########
55
Application Unquiesce for plugin: mysql
56
[10.35.84.19:9090 (4.1.1.1)] Operation failed. Verify that plugins/wrapper/wrapper binary has execute permission set. Increase the WRAPPER_TIMEOUT_IN_MSEC value in agent.properties if operations require more time to complete.
57
SCF-00033: Application unquiesce for plug-in [mysql] failed with exit code [102], proceeding with backup!
58
Application unquiesce result is empty from plugin mysql. skipping config update operation
59
Application UnQuiesce for plugin: mysql finished successfully
60
########## Application Unquiesce finished successfully ##########
61
########## Metadata Snapshot Create Commands Started  ##########
62
########## POST APPLICATION UNQUIESCE COMMANDS ##########
63
Post application unquiesce commands are not defined
64
########## POST APPLICATION UNQUIESCE COMMANDS FINISHED SUCCESSFULLY  ##########
65
########## Generating Info ASUP on nas40-ctrl2 ##########
66
STORAGE-01001: Creating AutoSupport message with event id [0], category [Backup Completed], description [INFO: Snap Creator Framework 4.1.2 Backup for titisnapshot ACTION: backup POLICY: SnapMirrorPolicy Plugin: mysql [Supported] Volumes: vol_db_data, finished], level [INFO], hostname [LMG40MDFOAM2 [10.35.84.19:9090]]
67
STORAGE-01002: Creating AutoSupport message with event id [0], category [Backup Completed], description [INFO: Snap Creator Framework 4.1.2 Backup for titisnapshot ACTION: backup POLICY: SnapMirrorPolicy Plugin: mysql [Supported] Volumes: vol_db_data, finished], level [INFO], hostname [LMG40MDFOAM2 [10.35.84.19:9090]] successful
68
ASUP finished successfully on nas40-ctrl2
69
Generating Info ASUP on NAS-ctrl2-LMG16
70
STORAGE-01001: Creating AutoSupport message with event id [0], category [SnapMirror Backup of NAS-ctrl2-LMG16:vol_db_data Started], description [INFO: Snap Creator Framework 4.1.2 SnapMirror Backup of NAS-ctrl2-LMG16:vol_db_data for titisnapshot ACTION: backup POLICY: SnapMirrorPolicy Plugin: mysql [Supported] Volumes: vol_db_data, Started], level [INFO], hostname [LMG40MDFOAM2 [10.35.84.19:9090]]
71
STORAGE-01002: Creating AutoSupport message with event id [0], category [SnapMirror Backup of NAS-ctrl2-LMG16:vol_db_data Started], description [INFO: Snap Creator Framework 4.1.2 SnapMirror Backup of NAS-ctrl2-LMG16:vol_db_data for titisnapshot ACTION: backup POLICY: SnapMirrorPolicy Plugin: mysql [Supported] Volumes: vol_db_data, Started], level [INFO], hostname [LMG40MDFOAM2 [10.35.84.19:9090]] successful
72
########## Running SnapMirror Update for source relationship nas40-ctrl2:vol_db_data ##########
73
STORAGE-02083: Updating SnapMirror relationship [nas40-ctrl2:vol_db_data -> NAS-ctrl2-LMG16:vol_db_data].
74
STORAGE-02084: Updating SnapMirror relationship [nas40-ctrl2:vol_db_data -> NAS-ctrl2-LMG16:vol_db_data] started successfully.
75
########## Post Data Transfer commands ##########
76
No commands defined
77
Post Data Transfer commands finished successfully
78
########## Post NTAP commands ##########
79
No Post NTAP commands defined
80
Post NTAP commands finished successfully
81
########## ARCHIVE COMMANDS ##########
82
Archive commands are not defined
83
########## Running Snapshot copy Delete on Primary ##########
84
Currently 5 snapshots exist. The retention count is specified as 1. The excess snapshots could not be deleted because they are not older than the retention age (1 days) for nas40-ctrl2:vol_db_data
85
########## Application cleanup ##########
86
Performing cleanup on : mysql
87
[10.35.84.19:9090 (4.1.1.1)] Operation failed. Verify that plugins/wrapper/wrapper binary has execute permission set. Increase the WRAPPER_TIMEOUT_IN_MSEC value in agent.properties if operations require more time to complete.
88
[10.35.84.19:9090(4.1.1.1)] SCF-00074: Cleanup for plug-in [mysql] failed with error [null] and exit code [102], Exiting!
89
Task: appCleanup with config:SnapMirrorProfile@MySqlConfig3 failed
90
########## Agent Workflow Finalization ##########
91
Agent Workflow Finalization started
92
[10.35.84.19:9090 (4.1.1.1)] Finalized workflow with id 35
93
Agent Workflow Finalization finished successfully
94
########## Snap Creator Framework 4.1.2 failed ##########
95
Pre Exit commands are not defined. Skipping !
1 ACCEPTED SOLUTION

Solved issue. In MySQL, you have to be careful about what is set in "Host" field. I had put the IP@ of Mysql server, whereas the host name was needed to match the mysql user corresponding host. I put "localhost" and it works now.

 

 [2015-10-19 15:29:28,432] INFO: Application Quiesce for plugin : mysql
[2015-10-19 15:29:39,041] INFO: [10.35.84.19:9090 (4.1.1.1)] (Mon Oct 19 15:29:36 2015) Quiescing databases
[2015-10-19 15:29:39,041] INFO: [10.35.84.19:9090 (4.1.1.1)] (Mon Oct 19 15:29:36 2015) Quiescing database bmsc
[2015-10-19 15:29:39,041] DEBUG: [10.35.84.19:9090 (4.1.1.1)] (Mon Oct 19 15:29:36 2015) Connection to bmsc successfully established
[2015-10-19 15:29:39,041] DEBUG: [10.35.84.19:9090 (4.1.1.1)] (Mon Oct 19 15:29:36 2015) Executing sql command 'flush tables with read lock' for database bmsc
[2015-10-19 15:29:39,042] DEBUG: [10.35.84.19:9090 (4.1.1.1)] (Mon Oct 19 15:29:36 2015) Executing sql command 'flush logs' for database bmsc
[2015-10-19 15:29:39,042] INFO: [10.35.84.19:9090 (4.1.1.1)] (Mon Oct 19 15:29:36 2015) Quiescing database bmsc finished successfully
[2015-10-19 15:29:39,042] INFO: [10.35.84.19:9090 (4.1.1.1)] (Mon Oct 19 15:29:36 2015) Quiescing databases finished successfully

View solution in original post

3 REPLIES 3

ssaravan

Please check agent logs to find out more details to find out what is causing quiesce failure.

EEntressangle

Thanks for your help.

 

I got the following logs :

 

[2015-10-16 15:33:14,663] INFO: Application Quiesce for plugin : mysql
12
[2015-10-16 15:33:25,014] INFO: [10.35.84.19:9090 (4.1.1.1)] (Fri Oct 16 15:33:22 2015) Quiescing databases
13
[2015-10-16 15:33:25,014] INFO: [10.35.84.19:9090 (4.1.1.1)] (Fri Oct 16 15:33:22 2015) Quiescing database bmsc
14
[2015-10-16 15:33:25,014] ERROR: [10.35.84.19:9090 (4.1.1.1)] (Fri Oct 16 15:33:22 2015) #42000Access denied; you need (at least one of) the RELOAD privilege(s) for this operation
15
[2015-10-16 15:33:25,014] ERROR: [10.35.84.19:9090 (4.1.1.1)] (Fri Oct 16 15:33:22 2015) [mys-00003] Quiescing databases finished with errors
16
[2015-10-16 15:33:25,015] ERROR: [10.35.84.19:9090(4.1.1.1)] SCF-00038: Application quiesce for plug-in [mysql] failed with exit code [1], continuing with backup.
17
[2015-10-16 15:33:25,016] INFO: Application quiesce result is empty  from plugin mysql. skipping config update operation
 
So I entered the following command in mysql CLI :
 
mysql>  grant RELOAD on *.* to 'root'@'localhost';
Query OK, 0 rows affected (0.00 sec)
 
But unfortunately problem still persists. Any idea ?
 
Thanks,
 
Regards

Solved issue. In MySQL, you have to be careful about what is set in "Host" field. I had put the IP@ of Mysql server, whereas the host name was needed to match the mysql user corresponding host. I put "localhost" and it works now.

 

 [2015-10-19 15:29:28,432] INFO: Application Quiesce for plugin : mysql
[2015-10-19 15:29:39,041] INFO: [10.35.84.19:9090 (4.1.1.1)] (Mon Oct 19 15:29:36 2015) Quiescing databases
[2015-10-19 15:29:39,041] INFO: [10.35.84.19:9090 (4.1.1.1)] (Mon Oct 19 15:29:36 2015) Quiescing database bmsc
[2015-10-19 15:29:39,041] DEBUG: [10.35.84.19:9090 (4.1.1.1)] (Mon Oct 19 15:29:36 2015) Connection to bmsc successfully established
[2015-10-19 15:29:39,041] DEBUG: [10.35.84.19:9090 (4.1.1.1)] (Mon Oct 19 15:29:36 2015) Executing sql command 'flush tables with read lock' for database bmsc
[2015-10-19 15:29:39,042] DEBUG: [10.35.84.19:9090 (4.1.1.1)] (Mon Oct 19 15:29:36 2015) Executing sql command 'flush logs' for database bmsc
[2015-10-19 15:29:39,042] INFO: [10.35.84.19:9090 (4.1.1.1)] (Mon Oct 19 15:29:36 2015) Quiescing database bmsc finished successfully
[2015-10-19 15:29:39,042] INFO: [10.35.84.19:9090 (4.1.1.1)] (Mon Oct 19 15:29:36 2015) Quiescing databases finished successfully

View solution in original post

Announcements
NetApp on Discord Image

We're on Discord, are you?

Live Chat, Watch Parties, and More!

Explore Banner

Meet Explore, NetApp’s digital sales platform

Engage digitally throughout the sales process, from product discovery to configuration, and handle all your post-purchase needs.

NetApp Insights to Action
I2A Banner
Public