| Bug #41600 | agent angel process spawning too soon - causing duplicate UUID error | ||
|---|---|---|---|
| Submitted: | 18 Dec 2008 20:18 | Modified: | 27 Feb 2009 12:58 |
| Reporter: | Ligaya Turmelle | ||
| Status: | Closed | ||
| Category: | Monitoring: Agent | Severity: | S2 (Serious) |
| Version: | 2.0.0.7111 , 2.0.2.7126 | OS: | Any |
| Assigned to: | MC Brown | Target Version: | 2.0.5 maint release |
| Tags: | mem_discuss_me | ||
| Triage: | Triaged: D2 (Serious) / R1 (None/Negligible) / E2 (Low) | ||
[30 Dec 2008 14:26]
Mark Leith
Patch submitted to Jan/Kay
[9 Jan 2009 17:40]
Diego Medina
Now I see this entry on the log 2009-01-09 11:36:58: (critical) agent_mysqld.c:609: agent connecting to mysql-server failed: mysql_real_connect(host = '127.0.0.1', port = 5130, socket = ''): Access denied for user 'agent_test'@'localhost' (using password: YES) (mysql-errno = 1045) but the agent is still running and on the Dashboard it shows the agent running but the monitored mysqld as stopped.
[28 Jan 2009 21:35]
Mark Leith
This happens when the agent lacks CREATE privileges on the mysql schema too.
[24 Feb 2009 21:31]
Diego Medina
Verified fixed on 2.0.5.7145 Not having enough privileges does not crash the agent any more, and there are no more duplicate UUID errors.
[27 Feb 2009 12:58]
Tony Bedford
An entry was added to the 2.0.5 changelog:
The agent angel process was spawning too soon, which caused a duplicate UUID error.
g_error() logged a fatal error, and called abort(). This terminated the program. Then the
angel respawned with the same UUID, but with a -1 session resync request, which the MEM
server denied because the old session was still active. This resulted in a permissions
denied error (1142) on the mysql.inventory table.
2008-12-17 18:58:58: (message) agent_mysqld.c:313: [mysql] mysqld is local and directly
connected
2008-12-17 18:58:58: ((error)) agent_mysqld.c:444: [mysql] mysql_real_query("SELECT
value
FROM mysql.inventory WHERE name = 'uuid'") failed: SELECT command denied to user
'ent_agent'@'127.0.0.1' for table 'inventory' (errno=1142)
2008-12-17 18:58:58: (debug) chassis.c:282: 15134 returned: 15134
2008-12-17 18:58:58: (message) chassis.c:304: [angel] PID=15134 died on signal=6 (it
used
0 kBytes max) ... waiting 3min before restart
2008-12-17 18:59:00: (debug) chassis.c:244: we are the child: 15149
2008-12-17 18:59:00: (message) chassis.c:259: [angel] we try to keep PID=15149 alive
2008-12-17 18:59:00: (debug) chassis.c:277: waiting for 15149
2008-12-17 18:59:00: (message) mysql-proxy 0.7.0 started
2008-12-17 18:59:00: (message) MySQL Monitor Agent 2.0.0.7111 started.
Description: 2008-12-17 18:58:58: (message) agent_mysqld.c:313: [mysql] mysqld is local and directly connected 2008-12-17 18:58:58: ((error)) agent_mysqld.c:444: [mysql] mysql_real_query("SELECT value FROM mysql.inventory WHERE name = 'uuid'") failed: SELECT command denied to user 'ent_agent'@'127.0.0.1' for table 'inventory' (errno=1142) 2008-12-17 18:58:58: (debug) chassis.c:282: 15134 returned: 15134 2008-12-17 18:58:58: (message) chassis.c:304: [angel] PID=15134 died on signal=6 (it used 0 kBytes max) ... waiting 3min before restart 2008-12-17 18:59:00: (debug) chassis.c:244: we are the child: 15149 2008-12-17 18:59:00: (message) chassis.c:259: [angel] we try to keep PID=15149 alive 2008-12-17 18:59:00: (debug) chassis.c:277: waiting for 15149 2008-12-17 18:59:00: (message) mysql-proxy 0.7.0 started 2008-12-17 18:59:00: (message) MySQL Monitor Agent 2.0.0.7111 started. g_error essentially logs a fatal error, and calls abort(). this terminates the program, and then the angel respawns with the same UUID, but a -1 session resync request, which the MEM server denies because the old session is still active. This was caused by a permissions denied error (1142) on the mysql.inventory table. How to repeat: 1) create a user that does NOT have SELECT permissions on the mysql.inventory table ( I gave mine SELECT access to every database BUT the mysql database). With all other agent permissions granted mysql> show grants for 'agent_test'@'localhost'; +------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | Grants for agent_test@localhost | +------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | GRANT INSERT, PROCESS, SHOW DATABASES, SUPER, REPLICATION CLIENT ON *.* TO 'agent_test'@'localhost' IDENTIFIED BY PASSWORD '*40EBE145368E7CEEC449ACD84470736718BF7307' | | | GRANT SELECT ON `sakila`.* TO 'agent_test'@'localhost' | | GRANT SELECT ON `test`.* TO 'agent_test'@'localhost' | | GRANT SELECT ON `world`.* TO 'agent_test'@'localhost' | | GRANT INSERT, CREATE ON `mysql`.* TO 'agent_test'@'localhost' | | +------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ 2) set the limited agent user to be used by the agent for the monitored DB (agent-instance.ini) 3) restart the agent so it uses the new limited user 4) see the agent error log 5) set it back to a user that has the correct permissions - wait for the session to timeout and restart the agent. Error disappears. except from my log: 2008-12-18 13:38:16: ((error)) agent_mysqld.c:444: [mysql] mysql_real_query("SELECT value FROM mysql.inventory WHERE name = 'uuid'") failed: SELECT command denied to user 'agent_test'@'localhost' for table 'inventory' (errno=1142) 2008-12-18 13:38:23: (critical) exception received from server: E1402: DuplicateAgentUuidException: [dbd0e622-4c40-45a4-b7ca-8308193a1a41] 2008-12-18 13:38:55: (critical) last message repeated 9 times 2008-12-18 13:38:55: (critical) exception received from server: E1402: DuplicateAgentUuidException: [dbd0e622-4c40-45a4-b7ca-8308193a1a41] Suggested fix: n/a