One of the key questions you should ask yourself as a serious Delphi developer is; what kind of exception handling and logging am I using. If you're not using any custom or third party solution for tracking down exceptional incidents that occur in your production systems or at your customer sites, you're missing out big time!
A proper exception handling and logging system should at least log the calling context (the calls that lead up to the exception) in the form of a stack trace. This makes it so much easier to track down, identify and fix the cause of the problem.
In 1999 I wrote such a tool and published it in The Delphi Magazine article Exceptional Stack Tracing in October 1999. As I have mentioned before, parts of this tool is based on my earlier work on 16-bit stack tracer, YAST. It also uses the excellent RTLI (run-time line information) tool by Vitaly Miryanov. At the time I was inspired by Per Larsen's ExHook32 and Stefan Hoffmeister's Debug Mapper. So I upgraded and improved the stack tracer for Win32, integrated the RTLI code and researched and developed a general implicit DLL import hooking system and a specific exception notification mechanism.
Putting all the pieces together we were able to get meaningful symbolic stack traces from any exceptional error incident - wether it happened during development, testing or at the customer's site. This made it an order of magnitude easier and faster to identify and fix bugs that caused the exception (or to handle it more gracefully).
I always spent a fair amount of time on my articles, but this one was by far the most time-consuming. Here are some key excerpts from the article.
"Often, during beta testing of an application (and, horrors, sometimes in a release version), users will encounter bugs in the form of exceptions (both logical such as EConvertError and hardware such as EAccessViolation). The tricky part is that only address of where the exception occurred is reported by the default Delphi exception handler. This is more often than not, less than helpful. Typically, that address will map to a line deep inside the VCL or RTL. What we’re really interested in is how we ended up there in the first place with invalid parameters (i.e. a blank string or a nil pointer). To get that we would need a complete stack trace of the calls that ended up in the exception being raised.
This article is about developing such an exception stack tracer. Not only will it show a complete stack trace leading up to an exception, but in the presence of so-called Run-Time Location Information (RTLI), it will also give a complete symbolic stack trace. "
"I remember reading an excellent article about PE files by Matt Pietrek[i]. In it he describes how implicit linking to external DLLs work. About the import address table, he says:
"Since the import address table is in a writeable section, it's relatively easy to intercept calls that an EXE or DLL makes to another DLL.. Simply patch the appropriate import address table entry to point at the desired interception function. There's no need to modify any code in either the caller or callee images. What could be easier?"
Yeah, what could be easier <g>? Such a statement just screams: “Implement me!”. We will implement a completely general way of hooking any routine in any implicitly loaded DLL. We can then use this technique to hook the Kernel32.RaiseException routine that is called from System._RaiseExcept. "
The key routine for hooking DLL imports is listed below:
function IsWin95CallThunk(Thunk: PWin95CallThunk): boolean;
begin
Result := (Thunk^.PUSH = $68) and (Thunk^.JMP = $E9);
end;
function ReplaceImport(Base: Pointer; ModuleName: PChar; FromProc, ToProc: pointer): boolean;
var
NtHeader : PImageNtHeaders;
ImportDescriptor : PImageImportDescriptor;
ImportEntry : PImageThunkData;
CurrModuleName : PChar;
IsThunked : Boolean;
FromProcThunk : PWin95CallThunk;
ImportThunk : PWin95CallThunk;
FoundProc : boolean;
begin
Result := false;
FromProcThunk := PWin95CallThunk(FromProc);
IsThunked := (Win32Platform = VER_PLATFORM_WIN32_WINDOWS) and
IsWin95CallThunk(FromProcThunk);
NtHeader := GetImageNtHeader(Base);
ImportDescriptor := PImageImportDescriptor(DWORD(Base)+
NtHeader.OptionalHeader.DataDirectory[IMAGE_DIRECTORY_ENTRY_IMPORT].VirtualAddress);
while ImportDescriptor^.NameOffset <> 0 do
begin
CurrModuleName := PChar(Base) + ImportDescriptor^.NameOffset;
if StrIComp(CurrModuleName, ModuleName) = 0 then
begin
ImportEntry := PImageThunkData(DWORD(Base) + ImportDescriptor^.IATOffset);
while ImportEntry^.FunctionPtr <> nil do
begin
if IsThunked then
begin
ImportThunk := PWin95CallThunk(ImportEntry^.FunctionPtr);
FoundProc := IsWin95CallThunk(ImportThunk) and
(ImportThunk^.Addr = FromProcThunk^.Addr);
end
else
FoundProc := (ImportEntry^.FunctionPtr = FromProc);
if FoundProc then
begin
ImportEntry^.FunctionPtr := ToProc;
Result := true;
end;
Inc(ImportEntry);
end;
end;
Inc(ImportDescriptor);
end;
end;
"Hooking RaiseException
Now that we have the HVHookDLL, it is very easy to hook the RaiseException routine in Kernel32.DLL – take a look at [the code below]"
unit HVExceptNotify;
interface
type
TExceptNotify = procedure (ExceptObj: TObject; ExceptAddr: pointer; OSException: boolean);
var
ExceptNotify: TExceptNotify;
implementation
uses
Windows,
SysUtils,
HVHookDLL;
var
Kernel32_RaiseException : procedure (dwExceptionCode, dwExceptionFlags, nNumberOfArguments: DWORD;
lpArguments: PDWORD); stdcall;
type
PExceptionArguments = ^TExceptionArguments;
TExceptionArguments = record
ExceptAddr: pointer;
ExceptObj : TObject;
end;
procedure HookedRaiseException(ExceptionCode, ExceptionFlags, NumberOfArguments: DWORD;
Arguments: PExceptionArguments); stdcall;
const
cDelphiException = {$IFDEF VER90}$0EEDFACE{$ELSE}$0EEDFADE{$ENDIF};
cNonContinuable = 1;
begin
if (ExceptionFlags = cNonContinuable) and
(ExceptionCode = cDelphiException) and
(NumberOfArguments = 7) and
(DWORD(Arguments) = DWORD(@Arguments) + 4) then
begin
if Assigned(ExceptNotify) then
ExceptNotify(Arguments.ExceptObj, Arguments.ExceptAddr, false);
end;
Kernel32_RaiseException(ExceptionCode, ExceptionFlags, NumberOfArguments, PDWORD(Arguments));
end;
var
SysUtils_ExceptObjProc: function (P: PExceptionRecord): Exception;
function HookedExceptObjProc(P: PExceptionRecord): Exception;
begin
Result := SysUtils_ExceptObjProc(P);
if Assigned(ExceptNotify) then
ExceptNotify(Result, P^.ExceptionAddress, true);
end;
function GetRaiseExceptAddr: pointer;
asm
LEA EAX, System.@RaiseExcept;
end;
initialization
SysUtils_ExceptObjProc := System.ExceptObjProc;
System.ExceptObjProc := @HookedExceptObjProc;
HookImport(Pointer(FindHInstance(GetRaiseExceptAddr)), 'Kernel32.dll', 'RaiseException', @HookedRaiseException, @Kernel32_RaiseException)
finalization
UnHookImport(Pointer(FindHInstance(GetRaiseExceptAddr)), 'Kernel32.dll', 'RaiseException', @HookedRaiseException, @Kernel32_RaiseException);
System.ExceptObjProc := @SysUtils_ExceptObjProc;
SysUtils_ExceptObjProc := nil;
end.
"The definition of what might be useful context information can vary according to what kind of application you are developing. The name of the currently focused form, the name of active database tables, the name of the logged in user and other global information might be useful. You can easily add any such value-added information yourself.
However, in all cases, a complete overview of the function calls that preceded the raised exception will be most useful. To get that, we have to implement something called a stack tracer. A stack tracer will analyze the current contents of the stack and try to figure out the return addresses stored there by the CPU as part of the CALL instruction operation.
YAST Nostalgia
[...] I have now converted [the 16-bit YAST stack tracer] to a 32-bit version and added some bells and whistles along the way – see the [code below]"
unit HVYAST32;
interface
uses
Windows,
SysUtils;
const
MaxBlock = MaxInt-$f;
type
PBytes = ^TBytes;
TBytes = array[0..MaxBlock div SizeOf(byte)] of byte;
PDWORDS = ^TDWORDS;
TDWORDS = array[0..MaxBlock div SizeOf(DWORD)] of DWORD;
PStackFrame = ^TStackFrame;
TStackFrame = record
CallersEBP : DWORD;
CallerAdr : DWORD;
end;
TStackInfo = record
CallerAdr : DWORD;
Level : DWORD;
CallersEBP : DWORD;
DumpSize : DWORD;
ParamSize : DWORD;
ParamPtr : PDWORDS;
case integer of
0 : (StackFrame : PStackFrame);
1 : (DumpPtr : PBytes);
end;
TReportStackFrame = function(var StackInfo: TStackInfo; PrivateData: Pointer): boolean;
procedure TraceStackFrames(ReportStackFrame: TReportStackFrame; PrivateData: Pointer);
procedure TraceStackRaw(ReportStackFrame: TReportStackFrame; PrivateData: Pointer);
const
MaxStackLevels = 50;
type
TStackInfoArray = array[0..MaxStackLevels-1] of TStackInfo;
var
StackDump: TStackInfoArray;
StackDumpCount: integer;
function PhysicalToLogical(Physical: DWORD): DWORD;
function DefaultReportStackFrame(var StackInfo: TStackInfo; PrivateData: Pointer): boolean;
procedure SaveStackTrace(Raw: boolean; IgnoreLevels: integer; FirstCaller: pointer);
implementation
uses
HVPEUtils;
{$W-}
function GetEBP: pointer;
asm
MOV EAX, EBP
end;
function GetESP: pointer;
asm
MOV EAX, ESP
end;
function GetStackTop: DWORD;
asm
MOV EAX, FS:[4]
end;
var
TopOfStack : DWORD;
BaseOfStack: DWORD;
BaseOfCode : DWORD;
TopOfCode : DWORD;
procedure InitGlobalVars;
var
NTHeader: PImageNTHeaders;
begin
if BaseOfCode = 0 then
begin
NTHeader := GetImageNtHeader(Pointer(hInstance));
BaseOfCode := DWord(hInstance) + NTHeader.OptionalHeader.BaseOfCode;
TopOfCode := BaseOfCode + NTHeader.OptionalHeader.SizeOfCode;
TopOfStack := GetStackTop;
end;
end;
function ValidStackAddr(StackAddr: DWORD): boolean;
begin
Result := (BaseOfStack < StackAddr) and (StackAddr < TopOfStack);
end;
function ValidCodeAddr(CodeAddr: DWORD): boolean;
begin
Result := (BaseOfCode < CodeAddr) and (CodeAddr < TopOfCode);
end;
function ValidCallSite(CodeAddr: DWORD): boolean;
var
CodeDWORD4: DWORD;
CodeDWORD8: DWORD;
begin
Result := (BaseOfCode < CodeAddr) and (CodeAddr < TopOfCode);
if Result then
begin
CodeDWORD8 := PDWORD(CodeAddr-8)^;
CodeDWORD4 := PDWORD(CodeAddr-4)^;
Result :=
((CodeDWORD8 and $FF000000) = $E8000000)
or ((CodeDWORD4 and $38FF0000) = $10FF0000)
or ((CodeDWORD4 and $0038FF00) = $0010FF00)
or ((CodeDWORD4 and $000038FF) = $000010FF)
or ((CodeDWORD8 and $38FF0000) = $10FF0000)
or ((CodeDWORD8 and $0038FF00) = $0010FF00)
or ((CodeDWORD4 and $FF000000) = $C3000000);
end;
end;
function NextStackFrame(var StackFrame: PStackFrame;
var StackInfo : TStackInfo): boolean;
begin
while ValidStackAddr(DWORD(StackFrame)) do
begin
if ValidCodeAddr(StackFrame^.CallerAdr) then
begin
Inc(StackInfo.Level);
StackInfo.StackFrame := StackFrame;
StackInfo.ParamPtr := PDWORDS(DWORD(StackFrame) + SizeOf(TStackFrame));
StackInfo.CallersEBP := StackFrame^.CallersEBP;
StackInfo.CallerAdr := StackFrame^.CallerAdr;
StackInfo.DumpSize := StackFrame^.CallersEBP - DWORD(StackFrame);
StackInfo.ParamSize := (StackInfo.DumpSize - SizeOf(TStackFrame)) div 4;
StackFrame := PStackFrame(StackFrame^.CallersEBP);
Result := true;
Exit;
end;
StackFrame := PStackFrame(StackFrame^.CallersEBP);
end;
Result := false;
end;
{$W+}
procedure TraceStackFrames(ReportStackFrame: TReportStackFrame; PrivateData: Pointer);
var
StackFrame : PStackFrame;
StackInfo : TStackInfo;
begin
StackInfo.Level := 0;
InitGlobalVars;
StackFrame := GetEBP;
BaseOfStack := DWORD(StackFrame) - 1;
while NextStackFrame(StackFrame, StackInfo) and
ReportStackFrame(StackInfo, PrivateData) do
;
end;
procedure TraceStackRaw(ReportStackFrame: TReportStackFrame; PrivateData: Pointer);
var
StackInfo : TStackInfo;
StackPtr : PDWORD;
PrevCaller: DWORD;
begin
BaseOfStack := DWORD(GetESP);
FillChar(StackInfo, SizeOf(StackInfo), 0);
InitGlobalVars;
PrevCaller := 0;
StackPtr := PDWORD(BaseOfStack);
while DWORD(StackPtr) < TopOfStack do
begin
if ValidCallSite(StackPtr^) and (StackPtr^ <> PrevCaller) then
begin
StackInfo.CallerAdr := StackPtr^;
PrevCaller := StackPtr^;
Inc(StackInfo.Level);
if not ReportStackFrame(StackInfo, PrivateData) then
Break;
end;
Inc(StackPtr);
end;
end;
function DefaultReportStackFrame(var StackInfo: TStackInfo; PrivateData: Pointer): boolean;
begin
Result := (StackDumpCount < MaxStackLevels-1);
if Result and
(DWORD(PrivateData) < StackInfo.Level) then
begin
StackDump[StackDumpCount] := StackInfo;
Inc(StackDumpCount);
end;
end;
procedure SaveStackTrace(Raw: boolean; IgnoreLevels: integer; FirstCaller: pointer);
begin
FillChar(StackDump, SizeOf(StackDump), 0);
StackDumpCount := 0;
if Assigned(FirstCaller) then
begin
StackDump[0].CallerAdr := DWORD(FirstCaller);
StackDumpCount := 1;
end;
if Raw
then TraceStackRaw (DefaultReportStackFrame, Pointer(IgnoreLevels))
else TraceStackFrames(DefaultReportStackFrame, Pointer(IgnoreLevels));
end;
const
LinkerOffset = $1000;
function PhysicalToLogical(Physical: DWORD): DWORD;
begin
Result := Physical
- DWORD(HInstance)
- LinkerOffset;
end;
end.
"To Stack Frame, or not to Stack Frame – that is the Question
There are generally two different types of algorithms to choose from when implementing a stack tracer: the more elegant stack frame based algorithm and the raw brute force algorithm.
[...]
The frame-based stack tracing is elegant and fairly fast, but it has one major weakness. It will not find callers that have no stack frames. With the current crop of optimising compilers, most smaller routines will not have stack frames and this reduces the usefulness of the stack tracer dramatically. There are two solutions to this. Either force stack frames for all your code – and preferably the VCL and RTL, too. Or use another algorithm.
[...]
[T]he brute-force method is much more primitive. The algorithm is very easy: just look at all the DWORDs stored on the stack. If a DWORD happens to be a value that falls within the valid code segment of this module, include it in the stack trace. To avoid getting too many false positives, we can add some more constraints."
"Dusting off the RTLI
While having the stack trace in hand is a great step in the right direction, it is still rather cumbersome having to locate the correct copy of the project’s MAP file (providing that we have it somewhere) and then start searching for each logical address from the stack trace.
Ideally, the stack trace itself should include symbolic information such as the unit name, filename, line number and routine name the logical address corresponds to. Thanks to Vitaly Miryanov and his RTLI[ii], we get this wonderful capability almost for free. He has already developed the framework and set of routines to make this possible. We just have to tweak the code a little to make it work with the newer compiler versions."
HVEST was a step in the right direction and using it is certainly better than nothing. If you are already using it you your code today, by all means continue to do so. But time has moved on and there are now more mature solutions available - including the open source JclDebug (as part of the JCL library) and the commercial madExcept, Exceptional Magic and EurekaLog. JclDebug was in part based on my HVEST code and brought forward by Petr Vones and others. If you haven't already, you should seriously consider using one of these - you will not regret it, believe me! ;)
As usual you can read the full article (PDF) and download the full, original code (zip). Enjoy!
[i] Matt Pietrek, MSJ March 1994: Peering inside the PE: A Tour of the Win32 Portable Executable File Format: http://msdn.microsoft.com/library/techart/msdn_peeringpe.htm
[ii] Vitaly Miryanov, TDM Issue 22, June 1997, Run-Time Location Information In Delphi 2
