GetTickCount / Fehler bei Bereichsprüfung

[Andidreas]

Hallo,

ich habe folgendes Problem...

Ich hab einen Service Programmiert der auf einem Windows Server 2008 R2 läuft...
Um die Performance meines Services zu überprüfen arbeite ich mit dem GetTickCount um die Start- und Endzeit zu stoppen...

Nun das kuriose...
Manchmal kann der Service ausgeführt werden, manchmal hängt er sich auf...
Aufhängen tut sich der Service an der Stelle wo ich über GetTickCount die Start Zeit in eine Integer Variable übernehme.
Als Exception Text bekomme ich "Fehler bei Bereichsprüfung"

Mir ist ausserdem noch aufgefallen dass:

1. ich mit derselben Logik auf einem Windows Server 2003 keine Probleme habe
2. ich auf meinem Windows 7 Notebook ebenfalls keine Probleme habe

Woher kommt der Fehler?
Bzw. mache ich was falsch?


Hier noch der Source wo ich Zeit abhole:

Delphi-Quellcode:

var
giTimerStart        : Integer;

begin

  //Set Result
  Result := rsSystem_Error;

  //Info Message
  prMsgLog(MySQL_Database, tyINF, 0, '', '', 'Save Master Data Tables...', gbBlckInfoMsg);
  prMsgLog(MySQL_Database, tyINF, 0, '', '', 'Delete Master Data Tables in DETMP', gbBlckInfoMsg);

  //Drop Tables in DETMP Schema
  Try
    If gsPerformCheck = 'YES' Then giTimerStart := GetTickCount();
  Except
    On E:Exception Do
    Begin
      prMsgLog(MySQL_Database, tyERR, 0, '', '', E.Message, gbBlckInfoMsg);
      Exit;
    End;
  End;

[Mikkey]

Kann es sein, dass ser 2008-er Server schon seit 24 oder mehr Tagen läuft?

Dann ist das High-Bit von GetTickCount gesetzt und das Ergebnis passt nicht mehr in den Integer.

[DeddyH]

GetTickCount

Zitat:

The elapsed time is stored as a DWORD value. Therefore, the time will wrap around to zero if the system is run continuously for 49.7 days. To avoid this problem, use the GetTickCount64 function. Otherwise, check for an overflow condition when comparing times.

Evtl. bringt es ja schon Besserung, giTimerStart als DWORD zu deklarieren oder bei der Zuweisung zu casten.

Delphi-Quellcode:

If gsPerformCheck = 'YES' Then giTimerStart := integer(GetTickCount());

[himitsu]

Da du ja anscheinend das ganze Projekt mit aktiver bereichsprüfung kompilierst, mußt du halt an solchen Stellen aufpassen.
(oder man deaktiviert an diesen stellen die Bereichsprüfung)

Bei impliziten Casts wird bei dir, vom Compiler, eine Bereichsprüfung eingebaut, während das bei expliziten Casts nicht passiert.


PS: Du mußt nicht nur bei der Zuweisung aufpassen, sondern auch bei der Berechnug.
Wenn Start vor dem Überlauf des Counters liegt und das Ende danach, dann wird auch das Zusammenrechnen abrauchen.

[Andidreas]

Ich habs grad geprüft...
Der Windows 2008 R2 Server wurde das letzte mal am 15.12. neu gestartet...

@DeddyH
Danke für den Tipp, werd ich gleich mal ausprobieren...
Wenn Deine Variante Funktioniert, muss man da was richtung Uptime berücksichtigen?

[DeddyH]

Welche Variante meinst Du, den Cast? Nunja, nach einer Uptime von knapp 25 Tagen wird das Ergebnis dann negativ, das Kernproblem bleibt also. Spricht denn etwas gegen GetTickCount64 wie von MS empfohlen?

[himitsu]

Bei dem expliziten Integer-Cast wird der binäre Wert in der Variable nicht verändert.

Man stellt da nur vor der Zuweisung die Interpretierung des höchsten Bits um, womit dann die Wertebereiche zusammen passen.

Stell dir es so vor:
Delphi erkennt, daß die beiden Typen nicht zusammen passen und macht intern aus deinem

Delphi-Quellcode:

MyInteger := MyCardinal;

ein

Delphi-Quellcode:

TempInt64 := MyCardinal;
if (TempInt64 < Low(MyInteger)) or (TempInt64 > High(MyInteger)) then
  raise exception....;
MyInteger := Integer(TempInt64);

Delphi-Quellcode:

MyInteger := Integer(MyCardinal);

tut jetzt so, als seien die 4 Byte in MyCardinal schon ein Integer, womit das gleich da rein passt.

[DeddyH]

Welche Variante meinst Du, den Cast? Nunja, nach einer Uptime von knapp 25 Tagen wird das Ergebnis dann negativ, das Kernproblem bleibt also. Spricht denn etwas gegen GetTickCount64 wie von MS empfohlen?

[Andidreas]

Also das mit dem Cast habe ich gerade wie folgt ausprobiert und das Ergebnis erscheint mir plausibel:

Delphi-Quellcode:

//Start Zeit  
If gsPerformCheck = 'YES' Then giTimerStart := Integer(GetTickCount());

//Differenz
If gsPerformCheck = 'YES' Then
Begin
  gdblTimeDiff := ((Integer(GetTickCount()) - giTimerStart)/1000);
  prMsgLog(MySQL_Database, tyINF, 99999, '', FloatToStrF(gdblTimeDiff, ffFixed, 5, 3), 'Delete Master Data Tables', gbBlckInfoMsg);
End;

Ich bräuchte eine Lösung die sowohl auf einem Windows 2003 Server als auch auf einem Windows 2008 R2 Server läuft...
Geht das mit dem GetTickCount64 in beiden Systemen (2003 & 2008)?

[himitsu]

Für eine Differenzberechnung reicht GetTickCount doch aus?
Also egal ob der Wert positiv oder negativ ist.

Zusammen mit dem Überlauf bekommt man dennoch immer einen positiven Wert raus, wenn Ende und Start summiert subtrahiert wurden. (solange die zu messende Zeit nicht größer als 2147483647 Millisekunden aka 24.86 Tage wird)

PS: auch bei GetTickCount64 gibt es irgendwann einen Überlauf ... man muß nur lange genug warten :angel2:

Zitat:

Geht das mit dem GetTickCount64 in beiden Systemen (2003 & 2008)?

Schau doch nach?
Im Gegensatz zu Emba erwähnt MS bei seinen APIs die Zielsysteme in seiner Hilfe (GetTickCount64).

[DeddyH]

Laut MSDN leider erst ab Windows Server 2008.
[edit] Vielleicht könnte man aber auch auf QueryPerformanceCounter/QueryPerformanceFrequency ausweichen, damit sollte das Problem eigentlich nicht bestehen. [/edit]

[Andidreas]

Wenn ich himitsu jetzt richtig verstanden habe, dann wäre doch meine Berechnung nach dem Casten wieder richtig oder sehe ich das falsch.

Spricht dann was dagegen wenn ich es so lasse wie ich es vorhin gepostet habe? Also den GetTickCount immer so abzufragen:

Delphi-Quellcode:

Integer(GetTickCount())

[himitsu]

Ja, das geht ... also entweder die Variable auf DWORD/Cardinal ändern oder das Funktions-Ergebnis nach Integer casten.

Aber, wie gesagt, du mußt auch bei den Berechnungen auspassen. (auch wenn da die Wahrscheinlichkeit viel kleiner ist, daß du diesen kleineren Zeitraum auch nochmal triffst, dort nach den fast genau 49.7 Tagen)

[DeddyH]

Wie von himitsu schon angedeutet musst Du dann aber berücksichtigen, dass der Wert nach 24,85 Tagen negativ wird und GetTickCount nach 49,7 Tagen wieder bei 0 beginnt.

[Andidreas]

Zitat:

Zitat von DeddyH (Beitrag 1243818)

Wie von himitsu schon angedeutet musst Du dann aber berücksichtigen, dass der Wert nach 24,85 Tagen negativ wird und GetTickCount nach 49,7 Tagen wieder bei 0 beginnt.

Ok, aber wenn gecastet wird ist das doch egal???
Sorry ich verstehs grad net ganz...

[DeddyH]

Du willst doch sicherlich eine Zeitmessung implementieren. Wenn Du nun mit GetTickCount eine Startzeit ermittelst und wiederum mit GetTickCount eine Endzeit, dann kann es passieren, dass die Endzeit negativ ist und die Startzeit positiv. Wenn Du nun also einfach so subtrahierst, ziehst Du eine positive Zahl von einer negativen ab, erhältst somit eine negative, mit der Du im Grunde nichts anfangen kannst. Um das zu vermeiden, müsstest Du bei der Subtraktion auch wieder beide Werte in DWORD casten. Wäre es da nicht besser, gleich DWORD zu nehmen?

[himitsu]

Casten muß man bei der Berechung eigentlich nicht. Alle Variablen müssen, während der Berechnung, nur den selben Typ besitzen.
Je nach dem, ob Integer oder Cardinal zum Rechnen verwendet wird, gibt es immer irgendwo einen Überlauf, beim Überreiten von High und Low,
was sich dann aber aufhebt, wenn der Wert danach wieder auf den selben Typ beschnitten wird.

Aber dort wird dann wieder die aktivierte Überlaufprüfung zuschlagen :zwinker:, weswegen diese Prüfung dort auf jeden Fall deaktiviert werden muß.


Bei GetTickCount64 kommt dieser Überlauf erst nach 600 Mio Jahren (falls ich mich nicht verschätzt hab).

[Andidreas]

Ok, jetzt hats klick gemacht, peinlich :oops: :oops: :oops:

Also wäre es so sinnvoller?

Delphi-Quellcode:

var
wrdStart, wrdEnd  : DWord;

If gsPerformCheck = 'YES' Then wrdStart := GetTickCount();

If gsPerformCheck = 'YES' Then
Begin
  wrdEnd := GetTickCount();
  gdblTimeDiff := ((wrdEnd - wrdStart)/1000);
  prMsgLog(MySQL_Database, tyINF, 99999, '', FloatToStrF(gdblTimeDiff, ffFixed, 5, 3), 'Delete Master Data Tables', gbBlckInfoMsg);
End;

[DeddyH]

IMO schon, nur bleibt eben das Problem mit der Uptime > 49,7 Tage. IIRC besteht das nicht, wenn man statt GetTickCount QueryPerformanceCounter und QueryPerformanceFrequency verwendet, sofern GetTickCount64 nicht in Frage kommt.

[p80286]

Frage, warum nicht die signifikanten Bits maskieren und davon dann die Differenz bilden?
Da kann mir der Wraparound doch egal sein?

Gruß
K-H

[himitsu]

QueryPerformanceCounter scheint aber auch ein paar Macken zu haben.

In dem Testprojekt vom himXML hatte ich das drin und auf meinem neuen i7 gibt das Ding keine verwertbaren Ergebnisse mehr raus, bzw. die Werte (also Count / Freq) stimmten absolut nicht.
z.B. Mehere Sekunden bis Tage ausgerechnet, aber real nur paar Millisekunden gelaufen oder auch mal andersrum.
Woran das lag, hatte ich auf die Schnelle nicht rausbekommen. (lag eventuell am Switchen der Treads in den 8 Kernen oder am ständigen hoch und runtergetackte der Kerne oder ein bug im Delphi)


Und den RealTimeStampCounter kann man uch schon länger nicht mehr verwenden, seitdem die CPUs dynamisch tackten und da wo der Counter-Takt an den CPU-Tackt gekoppelt ist.
Wenn er überall an die CPU gekoppelt wäre, hätte man damit wenigstens noch die "reale" CPU-Zeit messen können, aber das geht so ja nun auch nicht.

[Andidreas]

d.h. was würdet ihr vorschlagen?

[samso]

Ich hatte das mal so gelöst:

Delphi-Quellcode:

function TimeDiff(TickCount: Cardinal): Cardinal;
begin
  {$ifopt Q+}{$define recoveroverflowcheck}{$Q-}{$endif}
  Result := GetTickCount - TickCount;
  {$ifdef recoveroverflowcheck}{$Q+}{$endif}
end;

Diese Funktion kann nur eine maximal Zeitdifferenz von besagten 49 Tagen auswerfen. Wie lange der Rechner läuft spielt aber keine Rolle.

[Andidreas]

Meine Lösung wäre jetzt die folgende um über den QueryPerformanceCounter ein Performance Ergebnis in Sekunden zu bekommen:

Delphi-Quellcode:

var
intEnd, intFreq, intStart : Int64;

If gsPerformCheck = 'YES' Then QueryPerformanceCounter(intStart);

If gsPerformCheck = 'YES' Then
Begin
  QueryPerformanceCounter(intEnd);
  gdblTimeDiff := (((intEnd - intStart)/intFreq) * 1000) / 1000;
  prMsgLog(MySQL_Database, tyINF, 99999, '', FloatToStrF(gdblTimeDiff, ffFixed, 5, 3), 'Delete Master Data Tables', gbBlckInfoMsg);
End;

Die Berechnung müsste doch so stimmen???

[DeddyH]

Wenn sich intFreq aus QueryPerformanceFrequency ergibt, müsste das stimmen. Aber wieso erst mit 1000 multiplizieren und dann wieder dividieren?

[Andidreas]

uups hab was vom source vergessen, hier nochmal komplett:

Delphi-Quellcode:

var
intEnd, intFreq, intStart : Int64;

QueryPerformanceFrequency(intFreq);

If gsPerformCheck = 'YES' Then QueryPerformanceCounter(intStart);

If gsPerformCheck = 'YES' Then
Begin
  QueryPerformanceCounter(intEnd);
  gdblTimeDiff := (intEnd - intStart)/intFreq;
  prMsgLog(MySQL_Database, tyINF, 99999, '', FloatToStrF(gdblTimeDiff, ffFixed, 5, 3), 'Delete Master Data Tables', gbBlckInfoMsg);
End;

Keine Ahnung warum ich erst Multipliziert und dann wieder Dividiert hab :oops:
Liegt wohl an der Uhrzeit das ich schon etwas verwirrt bin :lol:

[Furtbichler]

Und das hier funktioniert nicht?

Delphi-Quellcode:

Function ElapsedTicks (previousTicks : Cardinal) : Cardinal;
Var
   currentTicks : Cardinal;

Begin
   currentTicks := GetTickCount();
   if currentTicks < previousTicks then
     result := High(Cardinal) - previousTicks + currentTicks + 1
   else
     result := currentTicks - previousTicks
end;



Var
  start : Cardinal;
...
begin
  start := GetTickCount;
  SomeOperation();
  Writeln('Tics elapsed:',ElapsedTicks(start));

[TiGü]

Ab, glaube ich, XE2 würde es noch die Möglichkeit der TStopWatch geben:

Delphi-Quellcode:

var
  MyStopWatch : System.Diagnostics.TStopwatch;
  ElapsedTimeInMilliSeconds : Int64;
  ElapsedTimeInSeconds,
  ElapsedTimeInMinutes,
  ElapsedTimeInHours,
  ElapsedTimeInDays : Double;
begin
  MyStopWatch := TStopwatch.StartNew;

  Sleep(10000);

  MyStopWatch.Stop;

  ElapsedTimeInMilliSeconds := MyStopWatch.ElapsedMilliseconds;
  ElapsedTimeInSeconds      := ElapsedTimeInMilliSeconds  / 1000;
  ElapsedTimeInMinutes      := ElapsedTimeInSeconds       / 60;
  ElapsedTimeInHours        := ElapsedTimeInMinutes       / 60;
  ElapsedTimeInDays         := ElapsedTimeInHours         / 24;
end;

[samso]

Zitat:

Zitat von Furtbichler (Beitrag 1243866)

Und das hier funktioniert nicht?

Delphi-Quellcode:

Function ElapsedTicks (previousTicks : Cardinal) : Cardinal;
Var
   currentTicks : Cardinal;

Begin
   currentTicks := GetTickCount();
   if currentTicks < previousTicks then
     result := High(Cardinal) - previousTicks + currentTicks + 1
   else
     result := currentTicks - previousTicks
end;



Var
  start : Cardinal;
...
begin
  start := GetTickCount;
  SomeOperation();
  Writeln('Tics elapsed:',ElapsedTicks(start));

Wenn man die Überlaufprüfung ausschaltet dann ist
result := High(Cardinal) - previousTicks + currentTicks + 1
equivalent zu
result := High(Cardinal) + 1 - previousTicks + currentTicks
equivalent zu
result := 0 - previousTicks + currentTicks
equivalent zu
result := currentTicks - previousTicks.
Die Fallunterscheidung ist dann also unnötig.

[Furtbichler]

Zitat:

Zitat von samso (Beitrag 1243926)

Die Fallunterscheidung ist dann also unnötig.

Jupp, aber ob er dann verständlicher wird? Ein Programmierer, dem der Überlauf auffällt, benötigt dann auch ein Weilchen, um das zu verstehen.

[himitsu]

Wenn man einfach ignoriert, daß es einen Überlauf geben könnte, dann ist es dennoch verstänglich.

[Furtbichler]

Zitat:

Zitat von himitsu (Beitrag 1243943)

Wenn man einfach ignoriert, daß es einen Überlauf geben könnte, dann ist es dennoch verstänglich.

Jo, is Auslegungssache. Und auch ein bisserl Wurschd