MySQL Slow Query Log - Interpretationsfrage

User avatar
daemotron
Administrator
Administrator
Posts: 2800
Joined: 2004-01-21 17:44

MySQL Slow Query Log - Interpretationsfrage

Post by daemotron »

Moin allerseits,

hab mich eben ein bisschen über die Zeitangaben in meinem Slow Query Log gewundert. Leider geht aus der MySQL-Dokumentation dazu nicht hervor, in welchen Zeiteinheiten da gemessen wird. Hier mal ein Auszug (bei long_query_time = 2):

Code: Select all

~ $ mysqldumpslow -t 1 /var/log/mysql/mysql.slow

Reading mysql slow query log from /var/log/mysql/mysql.slow

Count: 10  Time=4294967295.00s (-1s)  Lock=0.00s (0s)  Rows=0.0 (0), web1002[web1002]@[127.0.0.1]
  UPDATE pages
  SET
  SYS_LASTCHANGED='S'
  WHERE
  uid=N
Kann mir jemand verraten, wie ich die Angaben unter Time zu verstehen habe? Ich bekomme das einfach nicht zur Deckung mit den Laufzeitangaben des Programms, das die betreffende Query absetzt. da habe ich Laufzeiten im Bereich von ca. 350 - 500 Millisekunden...
Top

outofbound
Posts: 470
Joined: 2002-05-14 13:02
Location: Karlsruhe City

Re: MySQL Slow Query Log - Interpretationsfrage

Post by outofbound »

Top

User avatar
daemotron
Administrator
Administrator
Posts: 2800
Joined: 2004-01-21 17:44

Re: MySQL Slow Query Log - Interpretationsfrage

Post by daemotron »

Hallo Out,

den ersten Link hatte ich auch schon gefunden. In der Tat wird dort das selbe Phänomen beschrieben, aber eine Erklärung gibt's auch da nicht. mysqlsla werde ich mir definitiv mal anschauen, aber es kann IMHO nicht an mysqldumpslow liegen - wenn ich mir die Logdatei "roh" anschaue, finde ich dort dieselben merkwürdigen Angaben.

Gruss,
Jesco
Top

Roger Wilco
Administrator
Administrator
Posts: 6001
Joined: 2004-05-23 12:53

Re: MySQL Slow Query Log - Interpretationsfrage

Post by Roger Wilco »

Das Phänomen tritt auf, wenn die Zeit auf dem System nicht konsistent verläuft. Du hast vermutlich einen NTP-Client laufen, der die Zeit korrigiert. Wenn der Slow-Query dann gestartet wird, eine Weile läuft, währenddessen der NTP-Client die Zeit neu stellt und diese zufällig zurückgestellt wird (z. B. weil die Uhr auf dem System zu schnell läuft), hast du eine negative Zeitdifferenz zwischen Start und Ende der Abfrage.
Top