[dev.icinga.com #11947] Time to reconnect to MySQL IDO doubled with commit 0ce4139

[icinga-migration]

This issue has been migrated from Redmine: https://dev.icinga.com/issues/11947

Created by tobiasvdk on 2016-06-15 09:33:50 +00:00

Assignee: (none)
Status: Closed (closed on 2016-06-22 11:05:51 +00:00)
Target Version: (none)
Last Update: 2016-06-23 07:15:34 +00:00 (in Redmine)

Icinga Version: 2.4.10-?-g0ce4139
Backport?: Not yet backported
Include in Changelog: 1

---

Beginning with commit 0ce4139 the time icinga 2 needs to reconnect to the database doubled - in my environment (distributed cluster, ~2000 hosts and ~65000 services) from ~300 seconds to ~600 seconds on the master.

Changesets

2016-06-20 14:23:57 +00:00 by mfriedrich a86e381

DB IDO: Add missing object_id index for icinga_{scheduleddowntime,comments} tables

fixes #10070
refs #11947

2016-06-20 15:15:09 +00:00 by mfriedrich f10289a

DB IDO: Add missing object_id index for icinga_{scheduleddowntime,comments} tables

fixes #10070
refs #11947

---

Relations:

• relates #11947

[icinga-migration]

Updated by gbeutner on 2016-06-15 09:35:45 +00:00

• Category set to DB IDO
• Status changed from New to Assigned
• Assigned to set to mfriedrich

[icinga-migration]

Updated by mfriedrich on 2016-06-15 09:41:24 +00:00

• Status changed from Assigned to Feedback
• Assigned to changed from mfriedrich to tobiasvdk

Check the processlist and corresponding hanging DELETE statements for comments/downtimes. That's the only additional query caused by that change.

[icinga-migration]

Updated by gbeutner on 2016-06-20 07:16:30 +00:00

• Target Version set to 2.5.0

[icinga-migration]

Updated by mfriedrich on 2016-06-20 11:19:07 +00:00

Please test whether these additional indexes solve your issue.

CREATE INDEX comments_object_id_idx on icinga_comments(object_id);
CREATE INDEX scheduleddowntime_object_id_idx on icinga_scheduleddowntime(object_id);

[icinga-migration]

Updated by tobiasvdk on 2016-06-20 12:34:38 +00:00

In a first restart test the time was 314 seconds now.

Without the indexes:

[2016-06-20 11:46:20 +0000] information/IdoMysqlConnection: MySQL IDO instance id: 1 (schema version: '1.14.1')
[2016-06-20 11:46:30 +0000] information/IdoMysqlConnection: Query queue items: 27623, query rate: 0.7/s (42/min 42/5min 42/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:46:45 +0000] information/IdoMysqlConnection: Query queue items: 36050, query rate: 0.7/s (42/min 42/5min 42/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:47:00 +0000] information/IdoMysqlConnection: Query queue items: 80312, query rate: 0.7/s (42/min 42/5min 42/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:47:15 +0000] information/IdoMysqlConnection: Query queue items: 112126, query rate: 850.067/s (51004/min 51004/5min 51004/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:47:30 +0000] information/IdoMysqlConnection: Query queue items: 161767, query rate: 1648.83/s (98930/min 98972/5min 98972/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:47:45 +0000] information/IdoMysqlConnection: Query queue items: 197834, query rate: 1648.83/s (98930/min 98972/5min 98972/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:48:00 +0000] information/IdoMysqlConnection: Query queue items: 242459, query rate: 2441.5/s (146490/min 146532/5min 146532/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:48:15 +0000] information/IdoMysqlConnection: Query queue items: 279505, query rate: 2441.5/s (146490/min 146532/5min 146532/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:48:30 +0000] information/IdoMysqlConnection: Query queue items: 318507, query rate: 2441.5/s (146490/min 146532/5min 146532/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:48:45 +0000] information/IdoMysqlConnection: Query queue items: 359562, query rate: 1584.97/s (95098/min 194070/5min 194070/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:49:00 +0000] information/IdoMysqlConnection: Query queue items: 399343, query rate: 1584.97/s (95098/min 194070/5min 194070/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:49:15 +0000] information/IdoMysqlConnection: Query queue items: 438273, query rate: 1584.05/s (95043/min 241575/5min 241575/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:49:30 +0000] information/IdoMysqlConnection: Query queue items: 476283, query rate: 2374.97/s (142498/min 289030/5min 289030/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:49:45 +0000] information/IdoMysqlConnection: Query queue items: 516432, query rate: 2374.97/s (142498/min 289030/5min 289030/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:50:00 +0000] information/IdoMysqlConnection: Query queue items: 556168, query rate: 2374.13/s (142448/min 336518/5min 336518/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:50:15 +0000] information/IdoMysqlConnection: Query queue items: 594843, query rate: 2373.73/s (142424/min 383999/5min 383999/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:50:30 +0000] information/IdoMysqlConnection: Query queue items: 633562, query rate: 2373.73/s (142424/min 383999/5min 383999/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:50:45 +0000] information/IdoMysqlConnection: Query queue items: 673138, query rate: 2373.48/s (142409/min 431439/5min 431439/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:51:00 +0000] information/IdoMysqlConnection: Query queue items: 712530, query rate: 2374.37/s (142462/min 478980/5min 478980/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:51:15 +0000] information/IdoMysqlConnection: Query queue items: 751723, query rate: 2374.37/s (142462/min 478980/5min 478980/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:51:30 +0000] information/IdoMysqlConnection: Query queue items: 783423, query rate: 2374.7/s (142482/min 526439/5min 526481/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:51:45 +0000] information/IdoMysqlConnection: Query queue items: 805926, query rate: 2375.82/s (142549/min 573946/5min 573988/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:52:00 +0000] information/IdoMysqlConnection: Query queue items: 831638, query rate: 2375.82/s (142549/min 573946/5min 573988/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:52:15 +0000] information/IdoMysqlConnection: Query queue items: 873516, query rate: 2382.08/s (142925/min 621863/5min 621905/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:52:30 +0000] information/IdoMysqlConnection: Query queue items: 939634, query rate: 2382.08/s (142925/min 621863/5min 621905/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:52:45 +0000] information/IdoMysqlConnection: Query queue items: 976064, query rate: 2396.55/s (143793/min 571302/5min 670274/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:53:06 +0000] information/IdoMysqlConnection: Query queue items: 1000000, query rate: 2405.2/s (144312/min 619328/5min 718300/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:53:21 +0000] information/IdoMysqlConnection: Query queue items: 1000000, query rate: 2407.5/s (144450/min 619823/5min 766355/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:53:36 +0000] information/IdoMysqlConnection: Query queue items: 1000000, query rate: 2407.5/s (144450/min 619823/5min 766355/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:53:51 +0000] information/IdoMysqlConnection: Query queue items: 1000000, query rate: 2039.17/s (122350/min 646092/5min 792624/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:54:21 +0000] information/IdoMysqlConnection: Query queue items: 1000000, query rate: 1565.38/s (93923/min 618703/5min 860278/15min); empty in 1 hour, 36 minutes and 30 seconds
[2016-06-20 11:54:36 +0000] information/IdoMysqlConnection: Query queue items: 1000000, query rate: 2670.58/s (160235/min 637560/5min 926590/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:54:51 +0000] information/IdoMysqlConnection: Query queue items: 1000000, query rate: 3400.28/s (204017/min 660123/5min 996641/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 11:55:06 +0000] information/IdoMysqlConnection: Query queue items: 992970, query rate: 4148.57/s (248914/min 731645/5min 1068163/15min); empty in 35 minutes and 18 seconds
[2016-06-20 11:55:21 +0000] information/IdoMysqlConnection: Query queue items: 939331, query rate: 5183.92/s (311035/min 787314/5min 1171313/15min); empty in 4 minutes and 22 seconds
[2016-06-20 11:55:36 +0000] information/IdoMysqlConnection: Query queue items: 901574, query rate: 5246.45/s (314787/min 809938/5min 1241377/15min); empty in 5 minutes and 58 seconds
[2016-06-20 11:55:51 +0000] information/IdoMysqlConnection: Query queue items: 870689, query rate: 4911.22/s (294673/min 859875/5min 1291314/15min); empty in 7 minutes and 2 seconds
[2016-06-20 11:56:06 +0000] information/IdoMysqlConnection: Query queue items: 847352, query rate: 4845.6/s (290736/min 879919/5min 1358899/15min); empty in 9 minutes and 5 seconds
[2016-06-20 11:56:21 +0000] information/IdoMysqlConnection: Query queue items: 803289, query rate: 4542/s (272520/min 948253/5min 1443833/15min); empty in 4 minutes and 33 seconds
[2016-06-20 11:56:36 +0000] information/IdoMysqlConnection: Query queue items: 756591, query rate: 4733.03/s (283982/min 998878/5min 1525359/15min); empty in 4 minutes and 3 seconds
[2016-06-20 11:56:51 +0000] information/IdoMysqlConnection: Query queue items: 738873, query rate: 4699.03/s (281942/min 999268/5min 1573256/15min); empty in 10 minutes and 25 seconds
[2016-06-20 11:57:06 +0000] information/IdoMysqlConnection: Query queue items: 726390, query rate: 4287.42/s (257245/min 1042156/5min 1616144/15min); empty in 14 minutes and 32 seconds
[2016-06-20 11:57:21 +0000] information/IdoMysqlConnection: Query queue items: 692365, query rate: 4153.33/s (249200/min 1058965/5min 1680870/15min); empty in 5 minutes and 5 seconds
[2016-06-20 11:57:35 +0000] information/IdoMysqlConnection: Finished reconnecting to MySQL IDO database in 675.36 second(s).
[2016-06-20 11:57:36 +0000] information/IdoMysqlConnection: Query queue items: 654471, query rate: 3873.68/s (232421/min 1087506/5min 1757780/15min); empty in 4 minutes and 19 seconds
[2016-06-20 11:57:51 +0000] information/IdoMysqlConnection: Query queue items: 624860, query rate: 4363.32/s (261799/min 1155728/5min 1826002/15min); empty in 5 minutes and 16 seconds
[2016-06-20 11:58:06 +0000] information/IdoMysqlConnection: Query queue items: 585840, query rate: 4897.82/s (293869/min 1179130/5min 1897430/15min); empty in 3 minutes and 45 seconds
[2016-06-20 11:58:21 +0000] information/IdoMysqlConnection: Query queue items: 555284, query rate: 5045.18/s (302711/min 1198123/5min 1964478/15min); empty in 4 minutes and 32 seconds
[2016-06-20 11:58:36 +0000] information/IdoMysqlConnection: Query queue items: 502594, query rate: 4855.23/s (291314/min 1282739/5min 2049094/15min); empty in 2 minutes and 23 seconds
[2016-06-20 11:58:51 +0000] information/IdoMysqlConnection: Query queue items: 459638, query rate: 4985.88/s (299153/min 1332531/5min 2125155/15min); empty in 2 minutes and 40 seconds
[2016-06-20 11:59:06 +0000] information/IdoMysqlConnection: Query queue items: 419184, query rate: 4937.62/s (296257/min 1374438/5min 2193687/15min); empty in 2 minutes and 35 seconds
[2016-06-20 11:59:21 +0000] information/IdoMysqlConnection: Query queue items: 392976, query rate: 4718.4/s (283104/min 1387308/5min 2247586/15min); empty in 3 minutes and 44 seconds
[2016-06-20 11:59:36 +0000] information/IdoMysqlConnection: Query queue items: 348354, query rate: 4472.72/s (268363/min 1390867/5min 2317457/15min); empty in 1 minute and 57 seconds
[2016-06-20 11:59:51 +0000] information/IdoMysqlConnection: Query queue items: 295247, query rate: 4630.87/s (277852/min 1406366/5min 2403007/15min); empty in 1 minute and 23 seconds
[2016-06-20 12:00:06 +0000] information/IdoMysqlConnection: Query queue items: 255436, query rate: 4696.52/s (281791/min 1407315/5min 2475478/15min); empty in 1 minute and 36 seconds
[2016-06-20 12:00:21 +0000] information/IdoMysqlConnection: Query queue items: 233050, query rate: 4751.23/s (285074/min 1361347/5min 2532660/15min); empty in 2 minutes and 36 seconds
[2016-06-20 12:00:36 +0000] information/IdoMysqlConnection: Query queue items: 184277, query rate: 5203.77/s (312226/min 1392273/5min 2613296/15min); empty in 56 seconds
[2016-06-20 12:00:51 +0000] information/IdoMysqlConnection: Query queue items: 147201, query rate: 5145.27/s (308716/min 1400395/5min 2684186/15min); empty in 59 seconds
[2016-06-20 12:01:06 +0000] information/IdoMysqlConnection: Query queue items: 125107, query rate: 4549.98/s (272999/min 1389578/5min 2748477/15min); empty in 1 minute and 24 seconds
[2016-06-20 12:01:21 +0000] information/IdoMysqlConnection: Query queue items: 82513, query rate: 5023.9/s (301434/min 1390261/5min 2834059/15min); empty in 29 seconds
[2016-06-20 12:01:36 +0000] information/IdoMysqlConnection: Query queue items: 53736, query rate: 4802.08/s (288125/min 1376062/5min 2901379/15min); empty in 28 seconds
[2016-06-20 12:01:51 +0000] information/IdoMysqlConnection: Query queue items: 22523, query rate: 5002.22/s (300133/min 1398595/5min 2957907/15min);

With:

[2016-06-20 12:09:22 +0000] information/IdoMysqlConnection: MySQL IDO instance id: 1 (schema version: '1.14.1')
[2016-06-20 12:09:27 +0000] information/IdoMysqlConnection: Query queue items: 12844, query rate: 0.7/s (42/min 42/5min 42/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 12:09:42 +0000] information/IdoMysqlConnection: Query queue items: 52472, query rate: 0.7/s (42/min 42/5min 42/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 12:09:57 +0000] information/IdoMysqlConnection: Query queue items: 91203, query rate: 0.7/s (42/min 42/5min 42/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 12:10:12 +0000] information/IdoMysqlConnection: Query queue items: 130858, query rate: 0.7/s (42/min 42/5min 42/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 12:10:27 +0000] information/IdoMysqlConnection: Query queue items: 170866, query rate: 1649.7/s (98982/min 99008/5min 99008/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 12:10:42 +0000] information/IdoMysqlConnection: Query queue items: 214150, query rate: 3232.67/s (193960/min 194002/5min 194002/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 12:10:57 +0000] information/IdoMysqlConnection: Query queue items: 257675, query rate: 4595.1/s (275706/min 275748/5min 275743/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 12:11:12 +0000] information/IdoMysqlConnection: Query queue items: 300345, query rate: 5604.08/s (336245/min 336287/5min 336287/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 12:11:27 +0000] information/IdoMysqlConnection: Query queue items: 346418, query rate: 5534.5/s (332070/min 431078/5min 431078/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 12:11:42 +0000] information/IdoMysqlConnection: Query queue items: 393724, query rate: 5531.78/s (331907/min 525909/5min 525909/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 12:11:57 +0000] information/IdoMysqlConnection: Query queue items: 439423, query rate: 5536.42/s (332185/min 621039/5min 621039/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 12:12:12 +0000] information/IdoMysqlConnection: Query queue items: 485748, query rate: 6331.33/s (379880/min 668734/5min 668734/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 12:12:27 +0000] information/IdoMysqlConnection: Query queue items: 525456, query rate: 6322.3/s (379338/min 763033/5min 763033/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 12:12:42 +0000] information/IdoMysqlConnection: Query queue items: 566001, query rate: 5611.58/s (336695/min 815226/5min 815226/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 12:12:57 +0000] information/IdoMysqlConnection: Query queue items: 533013, query rate: 4014.1/s (240846/min 861885/5min 861885/15min); empty in 4 minutes and 2 seconds
[2016-06-20 12:13:12 +0000] information/IdoMysqlConnection: Query queue items: 506424, query rate: 4563/s (273780/min 942514/5min 942514/15min); empty in 4 minutes and 45 seconds
[2016-06-20 12:13:27 +0000] information/IdoMysqlConnection: Query queue items: 465278, query rate: 4179.42/s (250765/min 1013798/5min 1013798/15min); empty in 2 minutes and 49 seconds
[2016-06-20 12:13:42 +0000] information/IdoMysqlConnection: Query queue items: 430821, query rate: 4404.2/s (264252/min 1079478/5min 1079478/15min); empty in 3 minutes and 7 seconds
[2016-06-20 12:13:57 +0000] information/IdoMysqlConnection: Query queue items: 391063, query rate: 4837.18/s (290231/min 1146692/5min 1146692/15min); empty in 2 minutes and 27 seconds
[2016-06-20 12:14:12 +0000] information/IdoMysqlConnection: Query queue items: 346103, query rate: 4824.63/s (289478/min 1219066/5min 1219066/15min); empty in 1 minute and 55 seconds
[2016-06-20 12:14:27 +0000] information/IdoMysqlConnection: Query queue items: 263002, query rate: 5244.6/s (314676/min 1328432/5min 1328474/15min); empty in 47 seconds
[2016-06-20 12:14:37 +0000] information/IdoMysqlConnection: Finished reconnecting to MySQL IDO database in 314.273 second(s).
[2016-06-20 12:14:42 +0000] information/IdoMysqlConnection: Query queue items: 266087, query rate: 4714.37/s (282862/min 1362298/5min 1362340/15min); empty in infinite time, your database isn't able to keep up
[2016-06-20 12:14:57 +0000] information/IdoMysqlConnection: Query queue items: 226319, query rate: 4799.97/s (287998/min 1434648/5min 1434690/15min); empty in 1 minute and 25 seconds
[2016-06-20 12:15:12 +0000] information/IdoMysqlConnection: Query queue items: 182697, query rate: 4895.22/s (293713/min 1512737/5min 1512779/15min); empty in 1 minute and 2 seconds
[2016-06-20 12:15:27 +0000] information/IdoMysqlConnection: Query queue items: 157427, query rate: 4114.55/s (246873/min 1476339/5min 1575347/15min); empty in 1 minute and 33 seconds
[2016-06-20 12:15:42 +0000] information/IdoMysqlConnection: Query queue items: 118024, query rate: 4985.45/s (299127/min 1459268/5min 1653270/15min); empty in 44 seconds
[2016-06-20 12:15:57 +0000] information/IdoMysqlConnection: Query queue items: 104156, query rate: 4479.23/s (268754/min 1461999/5min 1703444/15min); empty in 1 minute and 52 seconds
[2016-06-20 12:16:12 +0000] information/IdoMysqlConnection: Query queue items: 76561, query rate: 4130.17/s (247810/min 1424302/5min 1760589/15min); empty in 41 seconds
[2016-06-20 12:16:27 +0000] information/IdoMysqlConnection: Query queue items: 35657, query rate: 4479.13/s (268748/min 1413015/5min 1844093/15min);

[icinga-migration]

Updated by tobiasvdk on 2016-06-20 13:54:57 +00:00

• Relates set to 10070

[icinga-migration]

Updated by mfriedrich on 2016-06-20 14:12:48 +00:00

So 665s vs 315s. I guess your old startup time was slightly higher as there probably were some downtimes/comments on the object and the DELETE statement was fired anyways.

[icinga-migration]

Updated by mfriedrich on 2016-06-22 11:05:51 +00:00

• Status changed from Feedback to Closed
• Assigned to deleted tobiasvdk
• Target Version deleted 2.5.0

Please try the additional indexes from the parent issue #10073 and e.g. #10066. This one is solved by the index from #10070.

[icinga-migration]

Updated by tobiasvdk on 2016-06-23 07:15:34 +00:00

Thx, will try them.