Wir betreiben einen m1.xlarge MySQL RDS-Server und haben einige Probleme mit der hohen CPU-Auslastung. Vor ein paar Wochen hatten wir einige Probleme mit der CPU-Auslastung, die auf einer großen Instanz 100% erreichte. Als wir die Größe auf xlarge hochrüsteten, stabilisierten sich die Dinge für eine Weile, aber die CPU-Auslastung stieg allmählich wieder an.
In den letzten Wochen lag die CPU-Auslastung in den hohen 90ern und erreichte gestern ungefähr 100%, was unseren Produktionsstandort zum Erliegen brachte. Nach dem Neustart des Datenbankservers stieg die CPU-Auslastung innerhalb weniger Stunden wieder auf das gleiche Niveau.
Ich habe show processlist auf dem MySQL-Server ausgeführt und das gleiche über den MySQL-Administrator überwacht. Es scheint auch keine besonders langen Abfragen oder eine große Anzahl von Abfragen zu geben. Es gibt einige Prozesse, die lange Zeit im Ruhezustand sind. Dies sind isolierte Worker-Daemons, die außerhalb unserer Haupt-App ausgeführt werden und mit der Datenbank kommunizieren. Ich habe in der folgenden Prozesslistenausgabe die Servernamen geändert, um eine Beschreibung zu geben, was sie sind:
+------+----------+---------------------------------------------------+--------------+---------+-------+--------------+----------------------------------------------------------------------------------------+
| Id | User | Host | db | Command | Time | State | Info |
+------+----------+---------------------------------------------------+--------------+---------+-------+--------------+----------------------------------------------------------------------------------------+
| 13 | rdsadmin | localhost:43513 | mysql | Sleep | 14 | | NULL |
| 15 | proddbuser | app-server-1.eu-west-1.compute.internal:36460 | proddb | Sleep | 46 | | NULL |
| 451 | proddbuser | app-server-1.eu-west-1.compute.internal:55512 | proddb | Sleep | 29 | | NULL |
| 912 | proddbuser | app-server-1.eu-west-1.compute.internal:45171 | proddb | Sleep | 13 | | NULL |
| 941 | proddbuser | app-server-1.eu-west-1.compute.internal:47353 | proddb | Sleep | 53 | | NULL |
| 951 | proddbuser | app-server-1.eu-west-1.compute.internal:48014 | proddb | Sleep | 37 | | NULL |
| 1009 | proddbuser | app-server-1.eu-west-1.compute.internal:51787 | proddb | Sleep | 36 | | NULL |
| 1041 | proddbuser | app-server-1.eu-west-1.compute.internal:53777 | proddb | Sleep | 14 | | NULL |
| 1572 | proddbuser | app-server-1.eu-west-1.compute.internal:42989 | proddb | Sleep | 3 | | NULL |
| 1592 | proddbuser | app-server-1.eu-west-1.compute.internal:43279 | proddb | Sleep | 162 | | NULL |
| 2909 | proddbuser | app-server-1.eu-west-1.compute.internal:37768 | proddb | Sleep | 35 | | NULL |
| 3028 | proddbuser | app-server-1.eu-west-1.compute.internal:42568 | proddb | Sleep | 5 | | NULL |
| 3119 | proddbuser | app-server-1.eu-west-1.compute.internal:46913 | proddb | Sleep | 76 | | NULL |
| 3189 | proddbuser | app-server-1.eu-west-1.compute.internal:51466 | proddb | Sleep | 5 | | NULL |
| 3216 | proddbuser | app-server-2.eu-west-1.compute.internal:44097 | proddb | Sleep | 14552 | | NULL |
| 3218 | proddbuser | app-server-2.eu-west-1.compute.internal:44099 | proddb | Sleep | 14552 | | NULL |
| 3219 | proddbuser | app-server-2.eu-west-1.compute.internal:44107 | proddb | Sleep | 44 | | NULL |
| 3220 | proddbuser | app-server-2.eu-west-1.compute.internal:44113 | proddb | Sleep | 26 | | NULL |
| 3223 | proddbuser | app-server-2.eu-west-1.compute.internal:44184 | proddb | Sleep | 50 | | NULL |
| 3224 | proddbuser | app-server-2.eu-west-1.compute.internal:44187 | proddb | Sleep | 1 | | NULL |
| 3226 | proddbuser | app-server-2.eu-west-1.compute.internal:44208 | proddb | Sleep | 33 | | NULL |
| 3229 | proddbuser | app-server-2.eu-west-1.compute.internal:44250 | proddb | Sleep | 14 | | NULL |
| 3232 | proddbuser | app-server-2.eu-west-1.compute.internal:44279 | proddb | Sleep | 26 | | NULL |
| 3233 | proddbuser | app-server-2.eu-west-1.compute.internal:44297 | proddb | Sleep | 31 | | NULL |
| 3237 | proddbuser | app-server-2.eu-west-1.compute.internal:44334 | proddb | Sleep | 27 | | NULL |
| 3239 | proddbuser | app-server-2.eu-west-1.compute.internal:44338 | proddb | Sleep | 11 | | NULL |
| 3241 | proddbuser | app-server-2.eu-west-1.compute.internal:44356 | proddb | Sleep | 26 | | NULL |
| 3260 | proddbuser | app-server-2.eu-west-1.compute.internal:44619 | proddb | Sleep | 8 | | NULL |
| 3337 | proddbuser | utility-server-1.eu-west-1.compute.internal:45193 | proddb | Query | 0 | Sending data | SELECT `mytable`.* FROM `mytable` WHERE `mytable`.`foreign_key` = 309416 LIMIT 1 |
| 3419 | proddbuser | utility-server-1.eu-west-1.compute.internal:46136 | proddb | Query | 0 | Sending data | SELECT `mytable`.* FROM `mytable` WHERE `mytable`.`foreign_key` = 284530 LIMIT 1 |
| 3463 | proddbuser | app-server-1.eu-west-1.compute.internal:59619 | proddb | Sleep | 9406 | | NULL |
| 3504 | proddbuser | utility-server-1.eu-west-1.compute.internal:47063 | proddb | Query | 0 | Sending data | SELECT `mytable`.* FROM `mytable` WHERE `mytable`.`foreign_key` = 260571 LIMIT 1 |
| 3577 | proddbuser | app-server-1.eu-west-1.compute.internal:34394 | proddb | Sleep | 6734 | | NULL |
| 3585 | proddbuser | utility-server-1.eu-west-1.compute.internal:47990 | proddb | Query | 0 | Sending data | SELECT `mytable`.* FROM `mytable` WHERE `mytable`.`foreign_key` = 231273 LIMIT 1 |
| 3664 | proddbuser | utility-server-1.eu-west-1.compute.internal:48909 | proddb | Query | 0 | Sending data | SELECT `mytable`.* FROM `mytable` WHERE `mytable`.`foreign_key` = 201525 LIMIT 1 |
| 3716 | proddbuser | app-server-2.eu-west-1.compute.internal:56301 | proddb | Sleep | 27 | | NULL |
| 3748 | proddbuser | utility-server-1.eu-west-1.compute.internal:49850 | proddb | Query | 0 | Sending data | SELECT `mytable`.* FROM `mytable` WHERE `mytable`.`foreign_key` = 167839 LIMIT 1 |
| 3771 | proddbuser | my-pc:30101 | NULL | Query | 0 | NULL | show processlist |
| 3831 | proddbuser | utility-server-1.eu-west-1.compute.internal:50785 | proddb | Query | 0 | Sending data | SELECT `mytable`.* FROM `mytable` WHERE `mytable`.`foreign_key` = 123228 LIMIT 1 |
+------+----------+---------------------------------------------------+--------------+---------+-------+--------------+----------------------------------------------------------------------------------------+Ich sollte auch sagen, dass der Verkehr auf der Website in diesem Zeitraum im Vergleich zu den normalen Stoßzeiten extrem niedrig ist. Dies entspricht etwa 10% der Last, die wir zu Stoßzeiten sehen.
Wir haben auch eine neue Reliktüberwachung, die uns zeigt, was die zeitaufwändigsten Aufrufe von App-Datenbanken sind. Es zeigt uns, dass ein bestimmter Anruf, der 99% der Zeit unserer App in der Datenbank ausmacht, eine einfache Suche nach ID-Abfragen wie diese ist:
SELECT `mytable`.* FROM `mytable` WHERE `mytable`.`id` = 123 LIMIT 1(nicht ganz dasselbe wie die Abfragen, die in der obigen Prozessliste ausgeführt wurden)
Dieser Vorgang ist in der letzten Woche langsamer geworden, wobei die Standardabweichung zwischen den Zeitanforderungen zunimmt und die maximale Zeitdauer in Sekunden gemessen wird. Ich denke, dies ist eher eine Folge der CPU-Auslastungsprobleme als eine Ursache.
Diese Tabelle hat ungefähr 80.000 Zeilen, ist also nicht riesig. Es wird erwartet, dass die meiste Zeit der Apps in der Datenbank damit verbracht wird, Datensätze in dieser Tabelle nachzuschlagen. Die Hauptfunktionalität der App basiert darauf. Ich habe selbst einige Male eine ähnliche Abfrage von meinem App-Server zur Produktionsdatenbank ausgeführt, während die CPU-Auslastung bei etwa 100% liegt und diese innerhalb von 1 oder 2 ms antwortet.
Aus all diesen Gründen sind wir uns nicht sicher, wie wir mit dem Debuggen fortfahren sollen. Ich habe mich nur gefragt, ob jemand eine Idee hat, welche Art von Dingen eine Grundursache sein könnten und wie man diese untersucht. Der Zugriff auf den zugrunde liegenden Server, auf dem unser Datenbankserver ausgeführt wird, ist beschränkt, da es sich um eine Amazon RDS-Instanz handelt.
Antworten:
Es ist mir gelungen, dieses Problem zu lösen. Dies sind die Schritte, die ich ausgeführt habe:
Erstens habe ich das Amazon RDS-Team kontaktiert, indem ich in ihrem Diskussionsforum einen Artikel gepostet habe. Sie haben bestätigt, dass der mysqld-Prozess die gesamte CPU beansprucht. Dadurch wurde ein Konfigurationsfehler behoben, bei dem auf dem physischen Server etwas anderes ausgeführt wurde
Zweitens habe ich die Quelle der Abfragen aufgespürt, die ausgeführt wurden:
Ich habe dies ursprünglich als Ursache übersehen, da keine dieser Abfragen besonders lange zu dauern schien, als ich die Ausgabe der Show-Prozessliste überwachte. Nachdem ich andere Möglichkeiten ausgeschöpft hatte, entschied ich, dass es sich lohnen könnte, nachzuschlagen ... und ich bin froh, dass ich es getan habe.
Wie Sie in der Ausgabe der show processlist sehen können, stammten diese Abfragen von einem Utlility-Server, auf dem einige taktische Utility-Jobs ausgeführt werden, die außerhalb unseres Hauptanwendungscodes existieren. Aus diesem Grund wurden sie in unserer neuen Reliktüberwachung nicht als langsam angezeigt und verursachten keine Probleme, da der neue Reliktagent nur auf unserem Haupt-App-Server installiert ist.
Befolgen Sie diese Anleitung:
http://www.mysqlperformanceblog.com/2007/02/08/debugging-sleeping-connections-with-mysql/
Ich konnte diese Abfragen auf einen bestimmten laufenden Prozess auf unserer Utility-Server-Box zurückverfolgen. Dies war ein bisschen Ruby-Code, der ungefähr 70.000 Datensätze ineffizient durchlief, einige Feldwerte überprüfte und anhand dieser Werte feststellte, ob ein neuer Datensatz in "mytable" erstellt werden muss. Nachdem ich einige Analysen durchgeführt hatte, konnte ich feststellen, dass der Prozess nicht mehr benötigt wurde und daher getötet werden konnte.
Etwas, das die Sache verschlimmerte, schien es, als ob 6 Instanzen desselben Prozesses gleichzeitig liefen, aufgrund der Art und Weise, wie der Cron-Job konfiguriert war und wie lange jeder dauerte! Ich habe diese Prozesse abgebrochen und unglaublich, dass unsere CPU-Auslastung von ungefähr 100% auf ungefähr 5% gesunken ist!
quelle