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 !

[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

[EEntressangle · 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