RPC-Threads verursachen nach Portierung von c++ 6.0 auf 2005 enorme CPU-Last

[elmut19]

Hallo zusammen,

ich habe nun schon wieder ein seltsames Problem mit meinen geerbten Software-Quellen. und das wieder am Freitag.

Ein älteres Programm habe ich von c++ 6.0 auf VS 2005 portiert, was eigentlich
gut verlaufen ist.

Dieses Programm arbeitet mit einigen RPC-Threads.
Diese treiben die bisherige CPU-Last von 1% - 2% auf über 60% in die Höhe.
Leider kenne ich mich mit RPC nicht aus (scheint auch etwas veraltet).
Nun habe ich "TRACES" eingebaut, um im Debugger einmal die Aufrufsequence abzuschätzen.
Sobald ich auch nur einen dieser TRACEs in einen der Threads eingesetzt hatte,
war die CPU-Last plötzlich wieder auf dem alten, niedrigen Stand.

Mein Vorgänger hat allerdings auch einige Sleep()-Funktionen eingebaut.
Im Debugger werden diese allerdings übersprungen, scheinen gar nicht da zu sein.

Ich habe auch mit SleepEx(x, FALSE) und SleepEx(x, TRUE) experimentiert.
Das scheint aber wieder andere seltsame Effekte zu haben, die ich gerade
nicht beurteilen kann. Aber wirklich keinen nennenswerten Effekt auf
die CPU-Last.

Kann mir da bitte jemand helfen?

Ich lege hier den kleinsten dieser Threads bei. Die anderen sind gleich aufgebaut.

UINT MyParamThread(LPVOID lpFenster)
//*****************************************************************************
{
	CTime		t1,t2,t3,t4;
	CTimeSpan	td;
	WORD i,wIntervall;

    CMainFrame *pCMain = (CMainFrame *)lpFenster;

	// Thread als gestartet kennzeichnen
	pCMain->bSetParamThreadRunning(TRUE);
	dwZaehlThr =0;
	t1 = CTime::GetCurrentTime();

	while(!pCMain->bTerminateParamThread() && !theApp.m_EndeClient)
	{	
  TRACE("MyParamThread: while running: %d \n", GetTickCount());// HP: debug Test wegen CPU-Last
		Sleep(1000);
		t2 = CTime::GetCurrentTime();
		td = (CTimeSpan)(t2-t1);
		if(td.GetTotalSeconds() > 1) {
		  if(theApp.m_pOwnMainWnd-> m_bWriteInfoToTraceProcInterface[5]) 
			   theApp.WriteLogfile(LOG_FEHLER, "MyParamThread: ","------------------------- Zeitdifferenz %d > 1 Sekunde",td.GetTotalSeconds());
		}

		pCMain->SetParamThreadOK();

		dwZaehlThr += td.GetTotalSeconds();
		for (i=0;i<=theApp.m_wMCAnzahl-1 && !pCMain->bTerminateParamThread();i++)
		{								
		  t4 = CTime::GetCurrentTime();
		  if(theApp.m_pOwnMainWnd->MrRgArray[i].pRegler==NULL) continue;
		  if(!theApp.m_pOwnMainWnd->MrRgArray[i].pRegler->bIsKommunikation()) continue;
		  if(    !theApp.m_pOwnMainWnd->MrRgArray[i].pRegler->bIsStartProz() 
			  && !theApp.m_pOwnMainWnd->MrRgArray[i].pRegler->m_fKontinuierlich) continue;
 		  wIntervall=theApp.m_pOwnMainWnd->MrRgArray[i].pRegler->wGetSpeicherInt();
		  if(wIntervall==0) continue;
		  if(!theApp.m_pOwnMainWnd->MrRgArray[i].pRegler->m_fAfzIntervallInSek) // Aufzeichnung in Sekunden
		   wIntervall*=60; 

		  if((theApp.m_pOwnMainWnd->MrRgArray[i].pRegler->m_cNextWriteTime - t2) > 0) continue;
		  theApp.m_pOwnMainWnd->MrRgArray[i].pRegler->m_cNextWriteTime	 = CTime::GetCurrentTime();
		  theApp.m_pOwnMainWnd->MrRgArray[i].pRegler->m_cNextWriteTime  += wIntervall;

//		  if((dwZaehlThr % wIntervall)!=0) continue;
		  theApp.m_pOwnMainWnd->MrRgArray[i].pRegler->vWriteIstDB(DB_WRITE_RSP_PARAMETER);
		  t3 = CTime::GetCurrentTime();
		  td = (CTimeSpan)(t3-t4);
		  if(td.GetTotalSeconds() > 1) {
		  if(theApp.m_pOwnMainWnd-> m_bWriteInfoToTraceProcInterface[5]) 
			   theApp.WriteLogfile(LOG_FEHLER, "MyParamThread: Dateneintrag ","Regler: %d ------------------------- Zeitdifferenz %d > 1 Sekunde",
			                       theApp.m_pOwnMainWnd->MrRgArray[i].pRegler->wGetReglerNr(),td.GetTotalSeconds());
		  }

		}//for

		t1 = CTime::GetCurrentTime();
		td = (CTimeSpan)(t1-t2);
		if(td.GetTotalSeconds() > 1) {
		  if(theApp.m_pOwnMainWnd-> m_bWriteInfoToTraceProcInterface[5]) 
			   theApp.WriteLogfile(LOG_FEHLER, "MyParamThread: Ende Dateneintrag ","------------------------- Zeitdifferenz %d > 1 Sekunde",td.GetTotalSeconds());
		}
	}//while(!pCMain->TerminateThread(0))

	// Thread als getötet kennzeichnen
	pCMain->bSetParamThreadRunning(FALSE);
	// Thread wiklich endlich beenden
	AfxEndThread(3);
	TRACE("MyParamThread beendet!");
	if(theApp.m_pOwnMainWnd-> m_bWriteInfoToTraceProcInterface[5]) 
	   theApp.WriteLogfile(LOG_FEHLER, "MyParamThread: ","ENDE");

	return(0);
}

[elmut19]

Kennt sich wirklich niemand ein Wenig mit RPC aus?
Kann es vielleicht auch an der Art der Initialisierung der RPC Threads liegen?
Kann/soll ich noch ein anderes Stück Quellcode nachliefern?
Warum wird die "Sleep()"-Anweisung nicht ausgeführt?
Ich verstehe dieses Thema leider nicht

[elmut19]

Eventuell habe ich mich auch getäuscht, und es liegt nicht am RPC.
Zumindest scheint nach genauerem Hinsehen der oben eingesetzte Quellcode nichts mit RPC zu tun zu haben, reagiert aber gleich wie die anderen.
In den anderen Threads habe ich Fragmente wie "m_pOwnMainWnd->m_RpcCallWriteRSP" gefunden.
Meine Fragen bleiben allerdings die selben.

[elmut19]

Statt der nicht funktionierenden "Sleep()" Aufrufe habe ich nun
Waitable Timer eingesetzt. Die erwartete Verbesserung blieb jedoch aus.
Im Debugger ging die CPU-Last auf ca. 38% statt vorher 63% zurück,
im Release sind es allerdings immer noch 50% CPU-Last.

Was kann ich denn noch machen? Weiss niemand einen Rat?

[elmut19]

Ich habe es nun doch selbst gelöst bekommen. (Kein RPC-Problem!)
Zum Einen hatte ich noch zwei versteckte Threads übersehen (peinlich).
Zum Anderen scheint das eigentliche Problem wohl doch in dem "Sleep()" zu liegen.

Bei meiner Suche nach einer Lösung bin ich auf einen kleinen Hinweis gestossen,
dass diese "Sleep"-Funktion wohl vom Compiler in manchen Situationen
ausgeblendet wird, da sie in er Situation nicht angebracht sei, was auch das
Verhalten des Debuggers erklären würde. So ganz wollte ich das einige Zeit lang
nicht glauben. Das Ergebnis scheint es aber zu belegen.

Allerdings scheint es da Unterscheide zu geben, je nach Methode, wie die Threads
erzeugt werden:
- Bei "CreateThread" scheint das "Sleep" noch zu funktionieren.
- Bei "AfxBeginThread" allerdings nicht
Das war leider ein zusätzliche Handicap.

Auch habe ich an verschiedenen Stellen gelesen, dass diese "Sleep"-Funktion nicht sonderlich toll programmiert sei (braucht anscheinend CPU-Zeit und hat Einfluss auf den restliche Programmlauf).

Vielleicht hat ja jemand noch eine genaue Erklärung dazu parat?

Also vielen Dank noch fürs Lesen.
Vielleicht nützt der Beitrag trotzdem irgend jemand.

Grüsse
Helmut

[hustbaer]

Scheint, scheint, scheint.
Du stocherst auch nur wild im Nebel herum.

Nein, der Compiler "blendet" keine Sleep-Aufrufe aus.
Und nein, Sleep ist auch nicht "nicht sonderlich toll programmiert".

Dein Problem kommt von woanders her.
Können wir aber unmöglich genauer eingrenzen, da wir dein Programm ja nicht da haben.

[elmut19]

Ja, gebe ich zu. Es ist ein Gestochere! Leider.
Wenn das Programm von mir stammen würde, würde ich mich auch besser damit auskennen. Ich hätte es auch anders geschrieben.

Leider kann auch kein Mensch überblicken, was man bei Microsoft so alles macht.
Früher hat was funktioniert und plötzlich funktionierts nicht mehr, nur wegen update auf neues Visual Studio.

Aber womit lässt sich die Tatsache erklären, dass der Debugger die Sleep-Funktion überspringt?

Der Beispiel-Code ist übrigens oben. (Der, der es geschrieben hat, hat wohl ein besonderes Verhältnich zu der Sleep-Funktion. die wurde hundertfach verwendet Gründe zweifelhaft)
Die betroffenen Threads werden mit "AfxBeginThread" erzeugt.
Bei anderen Threads, die mit CreateThread erzeugt wurden, gibt es diese Probleme nicht.

Nun habe ich alle Sleep-Funktionen in den fraglichen Threads durch WaitableTimer ersetzt.
Und siehe da, kein CPU-Resourcen Problem mehr.
Das ist für mich ein sehr deutliches Zeichen, dass es doch der Grund war.

Da ich nur meine etwas armsehlige Nachforschung als Grundlage habe und keine definitiven Aussagen von Microsoft, kann ich nur das Attribut "Es scheint so" verwenden.

Ich hatte die Hoffnung zu meinen Annahmen ev. eine klarere Aussage zu bekommen.

[hustbaer]

elmut19 schrieb:

Statt der nicht funktionierenden "Sleep()" Aufrufe habe ich nun
Waitable Timer eingesetzt. Die erwartete Verbesserung blieb jedoch aus.
Im Debugger ging die CPU-Last auf ca. 38% statt vorher 63% zurück,
im Release sind es allerdings immer noch 50% CPU-Last.

elmut19 schrieb:

Nun habe ich alle Sleep-Funktionen in den fraglichen Threads durch WaitableTimer ersetzt.
Und siehe da, kein CPU-Resourcen Problem mehr.
Das ist für mich ein sehr deutliches Zeichen, dass es doch der Grund war.

Also was jetzt?

Ich denke mir eher: kann nix bringen. Zumindest ist mir bisher noch kein Fall untergekommen wo Sleep vorzeitig beendet wurde (genauer: mehr als eine Zeitscheibe zu früh, nur eine Zeitscheibe hat üblicherweise so an die 15ms, bei einem Sleep(1000) darf das also keinen spürbaren Effekt haben). In der Doku steht auch nichts von dieser Möglichkeit.

SleepEx(..., TRUE) ist eine andere Geschichte, das kann durchaus früher zurückkommen - ist ja im Gegensatz zu Sleep "alertable". Und ja, das kann dann Nebeneffekte haben, weil "im" SleepEx dann APCs laufen können.

=> Bist du sicher dass es die Änderung Sleep => Waitable Timer war? Hast du nicht vielleicht gleichzeitig noch etwas anderes mit geändert?

[Martin Richter]

Also dieser Thread kann das Problem nicht verursachen.

Die 1000msec pro Schleifendurchlauf warden in jedem Fall eingehalten.
Es gibt keinen Fall in dem Sleeep hier wegpoptimiert wird vom Compiler.

[elmut19]

Ich habe nur das Sleep gegen den WaitableTimer ausgetauscht.
Zunächst hatte ich allerdings noch 2 solcher Threads übersehen, die
weiterhin mit Sleep gelaufen sind.

Und im Debugger wurden bei all diesen Threads die Sleep-Anweisungen übersprungen,
als ob es sich um einen Kommentar handeln würde. Also nicht einfach, dass die
Zeit nicht eingehalten wurde, sondern, die Anweisung war praktisch gar nicht da!

Ich habe das zunächst ignoriert, da ich mir nicht vorstellen konnte, dass
Microsoft so was macht. Aber anscheinend findet man bei Microsoft manche
Anweisungen in manchen Fällen als "nicht angebracht" und lässt sie gar nicht
erst zu. Obwohl man eigentlich seine Fehler machen könne sollte, wenn man
unbedingt will.

(Ich würde einen Thread allerdings auch nicht über "Sleep" steuern,
sondern einfache Timer verwenden. Aber mein Vorgänger hat das nun mal so gemacht. Somit war eine Funktion mit einem WaitableTimer ein direkter funktionaler Ersatz.)

Also "Sleep(1000)" wird einfach zu "DoWaitableTimerSleep(-1000000LL)"

Die Function "DoWaitableTimerSleep" habe ich 1:1 von Microsoft übernommen.

[hustbaer]

elmut19 schrieb:

Und im Debugger wurden bei all diesen Threads die Sleep-Anweisungen übersprungen,
als ob es sich um einen Kommentar handeln würde. Also nicht einfach, dass die
Zeit nicht eingehalten wurde, sondern, die Anweisung war praktisch gar nicht da!

Stell einfach mal den Cursor in einen Sleep-Aufruf, und drück F12.
Denn das kann eigentlich nur sein wenn Sleep als Makro definiert ist (das nix tut). Dann gibt es für die Zeile einfach keinen Code, und daher springt der Debugger auch einfach drpber.

Auf jeden Fall entfernt Visual Studio nicht von sich Aufrufe von DLL Funktionen. (Und auch keine Aufrufe von sonst irgendwelchen Funktionen wenn man ohne Optimierungen compiliert ODER die aufgerufenen Funktionen beobachtbare Nebeneffekte haben.)