Transcript Towards Effective Runtime Trace Generation Techniques in the .NET Framework

Towards Effective Runtime Trace
Generation Techniques in the
.NET Framework
Krisztián Pócza, Mihály Biczó, Zoltán Porkoláb
Eötvös Loránd University, Budapest
Faculty of Informatics
Department of Programming Languages and Compilers
The structure of this presentation
• Motivation, problem statement
• Tools: .NET Debugging and Profiling
Infrastructure
• Trace generation using the debugger
• Trace generation using the profiler
• Comparing the methods
• Future work
Motivation, problem statement
• Usage in industry
– Generate runtime trace during execution
• Real-world applications in production environment
• Non-intrusive
– No development environment allowed
– No debugging capabilities (no side effects)
– No human interaction
– Error detection
• Usage in academy
– Generate trace for program slicing
• Identify statements that affect a variable at a given program
location
.NET Debugging and Profiling
Infrastructure
• Design time interface
Symbol
Manager
– Debugging events
– Different process
– Notifications
Design time
int.
• Symbol manager
Profiler
CLR
– Interprets PDB files
– Identification of program elements
Publisher
.NET Debugging and Profiling
Infrastructure
Symbol
Manager
• Publisher
– Enumerates running
managed processes
in the system
• Profiler
Design time
int.
Profiler
CLR
Publisher
– Events
– Resource usage, CLR events (JIT, Load, GC,
memory allocation, exceptions, etc.)
Trace generation using the
debugger
• Based on MDbg (corapi2, corapi)
• Steps:
– Create process under the control of the
debugger
– Set a breakpoint at the program entry point
– Start the application
– After reaching the breakpoint do Step-in
operations
Trace generation using the
debugger
• What a debugging event (Step-in, breakpoint reached)
does:
– Sets evtComplete AutoResetEvent
– Waits for evtModState AutoResetEvent
• What the main program does in a while loop:
– Waits for evtComplete AutoResetEvent
– Generates trace about the current sequence point
– Sets evtModState AutoResetEvent
• Download:
– http://avalon.inf.elte.hu/src/netdebug/default.aspx
Trace generation using the profiler
• Technical background:
– In-process
– Implement a COM interface in C++ to handle
profiler events
– Environment variables must be set
– The assembly metadata should be extended
when loaded
• Reference for methods generating trace - Tokens
• ModuleLoadFinished profiler event
– Requires IL Code Rewriting
Trace generation using the profiler
• ClassLoadFinished
– Profiler event
– Visit all methods of the
class and rewrite
• Method types
– Tiny
– Fat
Tiny method
Header
IL Code
SEH Header
Ex. Hand. Clauses
Padding byte
• IL Instruction types
– No parameter, one integer parameter, token
parameter, multiple parameters
• Exception Handling Clauses (EHC)
– Try, catch, finally
Fat method
Trace generation using the profiler
• Code Rewriting steps:
– Query IL Code binary data
– Break it at sequence points
– Parse binary data and store it in custom data
structures (binary representation of every IL
instruction)
– Upgrade method and instruction format (*)
– Insert instrumentation code at every sequence
point(*)
– Recalculate offsets and lengths (*)
– Store the new representation in binary format
Trace generation using the profiler
• Upgrade method and instruction format
– Problems while inserting new IL instructions:
• Can break the limitations of tiny methods
• Short branch instructions’ maximum relative length can be
too short
• EHCs’ representation of offset and length limitation can be
too restrictive
– Solution
• Upgrade method format
• Convert short branch instructions to long branch instructions
• Store EHCs’ offset and length in DWORD instead of BYTE or
WORD
Trace generation using the profiler
• Insert instrumentation code at every SP
– Template:
BYTE insertFuncInst[31];
insertFuncInst[0] = 0x20; //ldc.i4, start line
insertFuncInst[5] = 0x20; //ldc.i4, start column
insertFuncInst[10] = 0x20; //ldc.i4, end line
insertFuncInst[15] = 0x20; //ldc.i4, end column
insertFuncInst[20] = 0x20; // ldc.i4, func. id
insertFuncInst[25] = 0x0; // ldc.i4.1 or ldc.i4.2
insertFuncInst[26] = 0x28; // call
*((DWORD *)(insertFuncInst+27)) = tracerDoFuncMethodTokenID;
– Substitute
• 1-4 bytes, 6-9, etc. bytes with current line and
column numbers
Trace generation using the profiler
• Recalculate offsets and lengths
– Recalculate method length
– Recalculate branch relative offsets
• Point to the first instruction of the new sequence
point if pointed to the first instruction of the old one
• Point to the same instruction of the new sequence
point if pointed to the not first instruction of the old
one
– Recalculate EHCs’ offset and length
Comparing the methods
• None of them require us to modify the original
source code
• Differences:
Debugger
Profiler
Speed
slow
fast
Multithread
one
many threads
Variables
Object ID, slow, easy
IL code rewriting, fast, hard
Variable
identification
Automatic for
reference type
variables using Object
ID
Have to implement
Comparing the methods
• Test results:
App. name
Normal run
Debugger
trace
Profiler trace
No. of SPs
Counter
00:00.17
01:53:92
00:01.34
110,034
ITextSharp
00:01:02
98:11.32
02:33:50
2,825,242
Disk-Reporter
00:05.46
24:04.42
00:11.76
316,196
Mohican
00:01.37
n/a
00:01.89
175,434
• Advance with the Profiler
Future work
• Variables of different types
– Almost finished
•
•
•
•
•
Exception handling
Anonymous methods
Generic types
Application domains
Integrate with program slicing
Demo
Q&A
Krisztián Pócza
[email protected]
Mihály Biczó
[email protected]
Zoltán Porkoláb
[email protected]