...someplace, where there isn't any trouble? Do you suppose there is such a place, Toto?

Woher kommt eigentlich der Begriff "Logging"?

Heute war eine interessante Diskussion mit Kollegen in deren Verlauf wir auf's Thema Logging zu sprechen kamen. Meine Frage in die Runde, wer denn wisse, woher der Begriff "Logging" oder "Logfile" kommt, wurde mit einem Achselzucken und "Vielleicht vom Logbuch?" beantwortet. Das ist soweit ganz richtig, aber woher kommt denn nun das "Logbuch"? Ein "Log" ist im britischen Idiom ein "Holzscheit", ist also der Windows Eventlog Service etwa ein Fensterereignisholzscheitdienst?

Und weil ich ja bekanntermaßen nicht nur ein Zeitgenosse von überragender Allgemeinbildung bin, sondern auch noch beinahe F.D.P.-haft anmutende Profilierungssucht und messianisches Sendungsbewußtsein zu meinen Kernkompetenzen zähle, habe ich die Erklärung gleich nachgeliefert: In der christlichen Seefahrt gehörte neben der Positionsbestimmung die Messung der Geschwindigkeit eines Schiffes zu denjenigen Dingen, die ins Logbuch eingetragen wurden, so daß man in der Lage war, den eigenen Kurs zu halten. Nun, wie mißt ein Segelschiff im 18. Jahrhundert seine eigene Geschwindigkeit? Ganz einfach, man stellt sich an den Bug des Schiffes, wirft einen schwimmfähigen Gegenstand ins Wasser und stoppt die Zeit, die vergeht, bis dieser am Ende des Schiffes vorbeizieht. Aus der bekannten Länge des Schiffes kann man gemäß v = s/t die aktuelle Geschwindigkeit näherungsweise bestimmen. Dieser schwimmfähige Gegenstand war in aller Regel ein Holzscheit, von denen man zu diesem Zweck immer eine ausreichende Anzahl an Bord mitführte. Und das Zeitnormal konnte man schon sehr früh ausreichend genau bereitstellen, sodaß man mit diesem einfachen Verfahren sehr gut bestimmen konnte wieviel Fahrt das Schiff gerade macht.

Fun with Globals - Der Loader Lock

Wer mich kennt, weiß daß ich sehr schnell ballistisch werde, wenn ich irgendwo Code sehe, der nichtriviale globale Objekte enthält, oder Code einer DLL, deren DllMain ganz dumme Sachen macht. Anhand eines Beispiels möchte ich hier jetzt einmal ein Phänomen vorstellen, das als "Loader Lock" bekannt ist.

Das Beispiel besteht aus einer ganz trivialen Exe-Datei ("Loader") und einer DLL ("Locker"). Mit Hilfe von Aufrufen des APIs Sleep provoziere ich eine Race Condition, wie sie im wirklichen Leben auch auftreten kann. Und damit niemand glaubt, daß das ein konstruiertes Beispiel sei: Es ist mir im richtigen Leben erst kürzlich begegnet. Das komplette Projekt (VC6) kann man sich hier downloaden

Erstmal hier der Code in der DLL:

#include "stdafx.h"
#include <tchar.h>

#define USE_GLOBAL_OBJECT 1


static void CreateAndWaitEvent()
{
  HANDLE hEvent = CreateEvent(NULL, FALSE, FALSE, 
    _T("oohdelalllyeh!"));
  if(hEvent)
  {
    WaitForSingleObject(hEvent, INFINITE);
    CloseHandle(hEvent);
  }
}

#if USE_GLOBAL_OBJECT
class CDoomed
{

  public:
    CDoomed()
    {
      CreateAndWaitEvent();
    }
};

CDoomed g_Doomed;

#endif 


BOOL APIENTRY DllMain( HANDLE /*hModule*/, 
                       DWORD  ul_reason_for_call, 
                       LPVOID /*lpReserved*/ )
{
#if !USE_GLOBAL_OBJECT
  if (DLL_PROCESS_ATTACH==ul_reason_for_call)
    CreateAndWaitEvent();    
#endif
  ul_reason_for_call;
  return TRUE;
}

Was passiert hier? Mit Hilfe des Makros USE_GLOBAL_OBJECT wird entschieden, ob entweder ein globales Objekt der Klasse CDoomed instanziiert wird (USE_GLOBAL_OBJECT=1), oder die Funktion CreateAndWaitEvent() (USE_GLOBAL_OBJECT=0) beim Process Attach der DLL aus DllMain heraus aufgerufen aufgerufen wird. Im ersteren Fall wird auch die Funktion CreateAndWaitEvent() aufgerufen, jedoch aus dem Konstruktor der Klasse CDoomed, von der die globale Instanz g_Doomed existiert.
Die Funktion CreateAndWaitEvent() erzeugt oder öffnet ein bereits existierendes Named Event Kernel Object mit dem Namen "oohdelalllyeh!". Auf dessen Signalisierung wartet diese Funktion und kehrt dann zum Aufrufer zurück. So weit so gut, ist ja schließlich keine wahrhafte Raketenwissenschaft.

Jetzt zu der Exe-Datei, ihr Code schaut folgendermaßen aus:

#include "stdafx.h"
#include <process.h>
#include <stdio.h>
#include <tchar.h>
#include <windows.h>

#ifndef dimof
#define dimof(a) (sizeof(a)/sizeof(a[0]))
#endif // dimof


unsigned __stdcall ThreadFunction(LPVOID)
{
  Sleep(5000);
  HMODULE hModule = LoadLibrary(_T("locker"));
  if (hModule)
    FreeLibrary(hModule);
  return TRUE;  
}

int main(int /*argc*/, char* /*argv*/[])
{
  unsigned tid;
  TCHAR szFileName[_MAX_PATH];

  HANDLE hEvent = CreateEvent(NULL, FALSE, FALSE, 
    _T("oohdelalllyeh!"));


  HANDLE hThread = (HANDLE)_beginthreadex(NULL, 0L, 
    ThreadFunction, NULL, 0L, &tid);

  Sleep(2000);
  
  GetModuleFileName(NULL, szFileName, dimof(szFileName));

  if (hEvent)
    SetEvent(hEvent);

  if (hThread)
  {
    _tprintf (_T("Now waiting for thread to terminate...\n"));
    WaitForSingleObject(hThread, INFINITE);
    CloseHandle(hThread);
  }

  if (hEvent)
    CloseHandle(hEvent);

  _tprintf (_T("Done!\n"));
	return 0;
}

Der Code der Exe-Datei erzeugt denselben named Event wie die DLL und startet dann einen Thread mit der Threadfunktion ThreadFunction. Wenn man nun die Aufrufe von Sleep außer acht läßt, dann macht dieser Secondary Thread nichts anderes, als die DLL zu laden. Der Primary Thread unterdessen ermittelt kurz den Pfad zum eigenen Modul mit GetModuleFileName und signalisiert dann den zuvor erzeugten Named Event um schließlich auf die Beendigung des Threads zu warten (dieses Warten hat mit den Race conditions nicht zu tun, es entspringt nur meiner guten Kodierkinderschule).

Man sollte also annehmen, dass der Ablauf des Programms der Folgende ist, was durch die Wahl der Werte für Sleep dem Scheduler von NT quasi nahegelegt wird:

  • Die Applikation erzeugt in der Exe-Datei den Named Event.
  • Der Thread wird gestartet, aber er legt sich erstmal für 5s schlafen.
  • Unterdessen besinnt sich der Code der Exe-Datei erstmal für 2s und schläft, dann ermittelt er seinen eigenen Pfad im Dateisystem (mit GetModuleFileName). Anschließend signalisiert er den Named Event und wartet auf das Terminieren des Threads.
  • Wir warten ca. 3s (Gähn!).
  • Der Thread lädt die DLL.
  • Der C-Runtime Startupcode führt den Konstruktor des globalen Objekts aus. Dieser öffnet nur nochmal ein zweites Handle zu dem bereits vorher erzeugten Named Event. Der Code der Exe-Datei hatte ja schon vorher den Event signalisiert, sodaß in der Funktion CreateAndWaitEvent die Wait-Operation ungestreift durchrauscht.
  • Die Dll wird wieder entladen und der Thread terminiert.
  • Der Code aus der exe, der auf das Terminieren des Threads wartet, kehrt aus seiner Wait-Operation zurück und main kehrt zurück in die C-Runtime.

Insgesamt sieht also das Ganze auf der Konsole so aus:

Lock

So, und jetzt spielen wir mal mit den Sleeps und machen aus den 5000 in der Threadfunktion nur noch schlappe 500.

Wenn wir jetzt den Prozeß erneut starten, stellen wir nach kürzester Zeit fest, daß sich der Prozeß nur noch durch höhere Gewalt beenden läßt. Schnell einen Debugger attacht und die Callstacks der Threads angeschaut. Und da stellt man dann Erstaunliches fest:

  • Der Secondary Thread steht in der Wait-Operation in der DLL und wartet darauf, daß der Named Event signalisiert wird.
  • Der Primary Thread ist im API GetModuleFileName steckengeblieben.

Ja, aber was ist denn hier passiert? Der Primary Thread kommt nie dazu, den Named Event zu signalisieren, weil er im API GetModuleFileName stecken bleibt. Der komplette Prozeß ist damit hoffnungslos im Deadlock, aber warum denn nur?

Es liegt daran, daß der Secondary Thread, der die DLL lädt, den "Loader Lock", den NT intern zur Serialisierung der DLL-Ladevorgänge einsetzt, für die Zeitdauer der LoadLibrary-Operation hat, aber das GetModuleFileName API diesen Lock halt dummerweise auch braucht.

Wenn man nun das Makro USE_GLOBAL_OBJECT auf 0 stellt, ändert sich am ganzen Verhalten nichts, denn Code, der beim Process Attach ausgeführt wird, unterscheidet sich praktisch in nichts von Code, der im Konstruktor eines globalen Objekts ausgeführt wird.

Und jetzt wird vielleicht auch klar, warum zu DllMain in der MSDN-Dokumentation folgendes steht:

"On attach, the body of your DLL entry-point function should perform only simple initialization tasks, such as setting up thread local storage (TLS), creating objects, and opening files. ... Calling Win32 functions other than TLS, object-creation, and file functions may result in problems that are difficult to diagnose. While it is acceptable to create synchronization objects in DllMain, you should not perform synchronization in DllMain (or a function called by DllMain) because all calls to DllMain are serialized. Waiting on synchronization objects in DllMain can cause a deadlock."

Das ist doch echt verständlich, oder? Und trotzdem sehe ich täglich nichttriviale globale Objekte, superkomplizierten DllMain-Code und andere Grausamkeiten und Fahrlässigkeiten, wie bespielsweise beliebig aufgerufene Funktionen mit Hilfe von Message-Passing-Patterns, wo weiß Gott was passieren kann (SCNR DEI!). Man mag das Ganze nun abtun als Spezialität von GetModuleFileName, aber es fallen natürlich statt GetModuleFileName noch viele weitere APIs darunter, darunter LoadLibrary selber und natürlich sämtliche erstmalige Aufrufe in eine gedelayloadete DLL. Allesamt Dinge, die ganz unschuldig mal so in den Code reinrutschen können, ohne daß jemand was Böses ahnt.

Die Moral von der Geschicht: Mach eine komplizierte DllMain nicht. Benutze ein Minimum an globalen Variablen und schon gar keine globalen Objekte. Wer's trotzdem tut sollte mit Codemaintenance nicht unter drei Jahren belohnt werden.

Über den Loader Lock hat übrigens Michael Grier hier so einiges geschrieben und gleich eine ganze Serie von Blogposts gemacht.

DISCLAIMER: Ein naiver Beobachter könnte nun meinen, ich sei ein Advokat des Einsatzes von Sleep zur Threadsynchronisation. Wer so denkt, sollte erwachsen werden und hat leider nichts verstanden und sollte mal dieses hier lesen und natürlich Fachliteratur wie den Tanenbaum und andere Classics.

Ein echter Hinkucker!

Hey, das ist cool!

Nach kürzester Zeit sieht man einen wandernden grünen Punkt, obwohl gar keiner da ist und wenn man auf unendlich fokussiert verschwinden die rosa Punkte komplett.

Muß ein API doppeltes Schließen eines HANDLEs oder Verwendung eines ungültigen HANDLEs aushalten?

Das war gestern die Frage in Mission Control und SFRs Standpunkt war: "Ja. auf jeden Fall!". Mein Standpunkt war: "Well, it depends." SFR schreibt nämlich gerade superfiesen Unittesting-Code und ist dabei einigen Läßlichkeiten in einem API von DEI auf die Spur gekommen. SFR hat nämlich ein HANDLE des APIs zweimal geschlossen und hat damit gerechnet, daß die Funktion zum Schließen beim zweiten Mal einen ordentlichen Fehlerrückgabecode liefert. Tatsächlich ist jedoch der Prozeß gecrasht. Jedenfalls war's so ähnlich. Bei den nachfolgenden Überlegungen gehe ich immer davon aus, daß das API in Form einer DLL implementiert ist und nicht als individuelle Source Files.

Wenn man solch einen Fehler *immer* graceful abhandeln will, muß man zu einigen Maßnahmen greifen, die vielleicht nicht unbedingt immer so schön sind. Was man braucht, ist dann immer ein Set (wenn man in STL denkt), das die aktuell für den Prozeß gültigen HANDLEs beinhaltet und jedes API, das ein HANDLE entgegennimmt, muß das HANDLE am Anfang prüfen und garantieren, daß im weiteren Verlauf der Codeausführung im API das HANDLE auch immer gültig bleibt, denn es könnte ja sein, daß unmittelbar nach der Gültigkeitsprüfung der aktuelle Thread preempted wird und ein nebenläufiger Thread das HANDLE schließt. Wenn dann der Thread im API wieder eine Zeitscheibe bekommt und weiter mit dem HANDLE operiert, kann es ja dann genauso scheppern. Die andere Variante wäre, daß man sich innerhalb der Prüfung, die natürlich von einer critsec geschützt sein muß, die threads gegenseitig ausschließt, alle relevanten Daten für den weiteren Verlauf des API-Codes kopiert und dann nur noch mit Kopien arbeitet.
All das erfordert aufwendige Synchronisationsmechanismen und nach meinem unmaßgeblichen Dafürhalten auch eine per-Prozeß-Initialisierungsroutine, die das prozeßweite HANDLE-Set und seine Synchronisationsobjekte aufsetzt, gepaart natürlich mit einer prozeßweiten Deinitialisierungsroutine. Denn wir benutzen ja keine globalen Objekte für sowas, die wir von der runtime Erzeugen lassen, oder? Doch? Und einen weiteren Effekt hat man dadurch: Alle APIs müssen zumindest eine zeitlang durch das prozeßweite HANDLE-Set durchtunneln, wodurch sich ein "Lock Convoy" ("Boxcar Problem") ergeben kann. Die Performance wird also zumindest nicht gesteigert durch sowas.

Es gibt aber auch einen psychologischen Aspekt des Problems: Eigentlich ist doppeltes Schließen eines HANDLEs oder ein Operieren mit ungültigen HANDLEs ein Programmierfehler, daran gibt es nichts zu deuteln. Ein Bruder-Leichtfuß-Programmierer, der ein API benutzt, tendiert schon auch mal dazu, Fehlercodes von APIs zu ignorieren und einfach nicht auszuwerten. Er wird also eventuell nie im Leben das doppelte Schließen des HANDLEs bemerken und vielleicht noch andere "silly things" (O-Ton SBRYANT) tun wenn er ungültige HANDLEs verwendet. Crasht hingegen sein Programm an dieser Stelle, kann er nicht umhin, sich mit dem Programmierfehler zu befassen. Ein super-graceful API kann also durchaus Fehler des API-Anwenders vertuschen.

Eine Variante des Themas wäre, daß das API nur die Verwendung von HANDLEs gestattet, die auch in dem Thread erzeugt wurden, wo sie verwendet werden, d.h. ich darf ein HANDLE nicht in einen anderen Thread weiterreichen. Damit hätte man unter dem Preis dieser Limitation das Boxcar-Problem beseitigt. Das setzt dann aber ein per-thread-HANDLE-Set, einen per-Thread-Initialisierer/Deinitialisierer und einen TLS-Slot mehr pro-Prozess voraus und TLS-Slots sind knappe prozeßweite Ressourcen. There ain't no such thing as a free meal.

Drum bin ich der Meinung, daß man die Frage im Subject dieses Blogposts für jedes API im Einzelfall prüfen und festlegen muß, es aber eine pauschale Antwort nicht geben kann.

(Edited: Fixed Typos)

A helluva lot of Quickies!

Heute war ein ereignisreicher Tag. In und um Mission Control gab es die interessantesten Dinge zu bestaunen. Beispielweise im Hautatmer-Office nebenan Incis Kugelschreiber. Der schaut nämlich so aus:

Natürlich behauptet Inci, das sei der Kugelschreiber vom Benni, aber der Kugelschreiber lag eindeutig an Incis Platz, nicht an dem von Benni, isch'schwör. Man könnte sich natürlich jetzt auf den Standpunkt stellen, daß ein Kuli an sich schon ein gewisses phallisches Potential hat, aber wenn ich ein Marketingmensch bei Pfizer wäre, würden mir durchaus phantasievollere Kugelschreiberformfaktoren einfallen.

Auch interessant: Der Beweis, daß ohne den DEI gar nichts geht, wenn schon unser SGL auf der Suche nach ihm swingtanzenderweise Kurs auf Mission Control nimmt:

Und das, obwohl sowohl Kreationisten (mein braver, treuer Deputy) wie Quartisten (meine bescheidene Wenigkeit) das in seltener Einmut verboten haben, wie unser Emailleschild eindeutig belegt:

Aber den X-Wing abgeschossen hat heute Anne-kin Fischer. Über sie haben wir in diesem Zusammenhang schon in der Vergangenheit berichtet. Doch als bedürfte es noch weiterer Beweise, daß sich in der hoffnungsvollen jungen Jedi, die sich zu unserem allergrößten Bedauern so sehr zur dunklen Seite der Macht hingezogen fühlt, so allmählich die Verwandlung zu Darth Ännchen vollzieht, ist sie heute mit echten Star-Wars-Stormtrooper-Boots bei επτ€σ aufgeschlagen:

Und weil man uns das nicht glaubt und uns morgen wieder jeder unterstellt, wir hätten das Bild aus irgendeinem Leder-Fetisch-Webshop geklaut, hier das ganze in der Totalen:

Deutlich erkennbar hat sie den fiesen Blick des mit der geballten Faust auf Rache für Padmé sinnenden Anakin Skywalker schon perfekt drauf. Wahrscheinlich hat sie das mit diesem Bild geübt. Mission Control muß sich vorsehen - vielleicht brauchen wir noch mehr Laserschwerter.

(Ein Klick auf ein Bild lädt es in höherer Auflösung in einem separaten Browserfenster)
(Edited: Der Link fuer Darth Ännchens Vorbild-Bild war a bissal flaky und ist jetzt durch einen hoffentlich robusteren ersetzt worden)

<< 1 ... 34 35 36 37 38 39 40 41 42 43 44 ... 46 >>