Comment 3 for bug 1853071

Not seeing the DBDeadlock stacktraces in neutron logs yet. but Here's some more logs/info fro mysql side:

These are the queries that we can see mysql is repeatedly executing. See the age/time increase to 60, then a new query with different localhost:PORTNUM is observed. Sometimes the agent.id is different. But when it tries the same agent.id again, What is strange is the heartbeat timestamp is off by a fraction of a second. Is this a different state report RPC altogether, or is timestamp recalculated on server side?

mysql> SELECT host,time, INFO FROM INFORMATION_SCHEMA.PROCESSLIST where INFO is NOT NULL and DB ='neutron' ORDER BY time DESC LIMIT 30;
+-----------------+------+----------------------------------------------------------------------------------------------------------------------------------+
| host | time | INFO |
+-----------------+------+----------------------------------------------------------------------------------------------------------------------------------+
| localhost:50606 | 6 | UPDATE agents SET heartbeat_timestamp='2019-11-19 21:54:18.817098' WHERE agents.id = '17443741-0a8f-4cbb-9bc3-94b6407d849b' |
| localhost:39315 | 6 | UPDATE agents SET heartbeat_timestamp='2019-11-19 21:49:01.483936' WHERE agents.id = '17443741-0a8f-4cbb-9bc3-94b6407d849b' |
| localhost | 0 | SELECT host,time, INFO FROM INFORMATION_SCHEMA.PROCESSLIST where INFO is NOT NULL and DB ='neutron' ORDER BY time DESC LIMIT 30 |
+-----------------+------+----------------------------------------------------------------------------------------------------------------------------------+
3 rows in set (0.00 sec)

mysql> SELECT host,time, INFO FROM INFORMATION_SCHEMA.PROCESSLIST where INFO is NOT NULL and DB ='neutron' ORDER BY time DESC LIMIT 30;
+-----------------+------+----------------------------------------------------------------------------------------------------------------------------------+
| host | time | INFO |
+-----------------+------+----------------------------------------------------------------------------------------------------------------------------------+
| localhost:50608 | 42 | UPDATE agents SET heartbeat_timestamp='2019-11-19 21:54:18.823186' WHERE agents.id = '5e0f0692-4f55-4a35-9efa-12aa866153a2' |
| localhost:39317 | 42 | UPDATE agents SET heartbeat_timestamp='2019-11-19 21:49:01.487855' WHERE agents.id = 'e2682460-c019-43fd-848b-871a5b7c13bf' |
| localhost | 0 | SELECT host,time, INFO FROM INFORMATION_SCHEMA.PROCESSLIST where INFO is NOT NULL and DB ='neutron' ORDER BY time DESC LIMIT 30 |
+-----------------+------+----------------------------------------------------------------------------------------------------------------------------------+
3 rows in set (0.01 sec)

mysql> SELECT host,time, INFO FROM INFORMATION_SCHEMA.PROCESSLIST where INFO is NOT NULL and DB ='neutron' ORDER BY time DESC LIMIT 30;
+-----------------+------+----------------------------------------------------------------------------------------------------------------------------------+
| host | time | INFO |
+-----------------+------+----------------------------------------------------------------------------------------------------------------------------------+
| localhost:50610 | 7 | UPDATE agents SET heartbeat_timestamp='2019-11-19 21:54:18.830226' WHERE agents.id = '17443741-0a8f-4cbb-9bc3-94b6407d849b' |
| localhost:39319 | 7 | UPDATE agents SET heartbeat_timestamp='2019-11-19 21:49:01.491844' WHERE agents.id = '17443741-0a8f-4cbb-9bc3-94b6407d849b' |
| localhost | 0 | SELECT host,time, INFO FROM INFORMATION_SCHEMA.PROCESSLIST where INFO is NOT NULL and DB ='neutron' ORDER BY time DESC LIMIT 30 |
+-----------------+------+----------------------------------------------------------------------------------------------------------------------------------+
3 rows in set (0.00 sec)

mysql> SELECT host,time, INFO FROM INFORMATION_SCHEMA.PROCESSLIST where INFO is NOT NULL and DB ='neutron' ORDER BY time DESC LIMIT 30;
+-----------------+------+----------------------------------------------------------------------------------------------------------------------------------+
| host | time | INFO |
+-----------------+------+----------------------------------------------------------------------------------------------------------------------------------+
| localhost:39321 | 23 | UPDATE agents SET heartbeat_timestamp='2019-11-19 21:49:01.496304' WHERE agents.id = 'e2682460-c019-43fd-848b-871a5b7c13bf' |
| localhost:52431 | 22 | UPDATE agents SET heartbeat_timestamp='2019-11-19 21:55:09.871667' WHERE agents.id = '17443741-0a8f-4cbb-9bc3-94b6407d849b' |
| localhost | 0 | SELECT host,time, INFO FROM INFORMATION_SCHEMA.PROCESSLIST where INFO is NOT NULL and DB ='neutron' ORDER BY time DESC LIMIT 30 |
+-----------------+------+----------------------------------------------------------------------------------------------------------------------------------+
3 rows in set (0.00 sec)

mysql> SELECT host,time, INFO FROM INFORMATION_SCHEMA.PROCESSLIST where INFO is NOT NULL and DB ='neutron' ORDER BY time DESC LIMIT 30;
+-----------------+------+----------------------------------------------------------------------------------------------------------------------------------+
| host | time | INFO |
+-----------------+------+----------------------------------------------------------------------------------------------------------------------------------+
| localhost:39321 | 48 | UPDATE agents SET heartbeat_timestamp='2019-11-19 21:49:01.496304' WHERE agents.id = 'e2682460-c019-43fd-848b-871a5b7c13bf' |
| localhost:52431 | 47 | UPDATE agents SET heartbeat_timestamp='2019-11-19 21:55:09.871667' WHERE agents.id = '17443741-0a8f-4cbb-9bc3-94b6407d849b' |
| localhost | 0 | SELECT host,time, INFO FROM INFORMATION_SCHEMA.PROCESSLIST where INFO is NOT NULL and DB ='neutron' ORDER BY time DESC LIMIT 30 |
+-----------------+------+----------------------------------------------------------------------------------------------------------------------------------+
3 rows in set (0.00 sec)

Meanwhile Rabbit q-reports-plugin queue keeps growing, possibly indicating mysql transactions updates are taking too long or blocked waiting for locks. Given that agent HB interval is 30 seconds and RPC retry timeout is 240+ seconds, leads me to believe neutron is stuck retrying the same SQL query