Dynamic Execution Tracing of Physical Simulations Jonathan Cohen The Motivation • Typical bugs in physical simulation are hard to find! • Complex code path.
Download ReportTranscript Dynamic Execution Tracing of Physical Simulations Jonathan Cohen The Motivation • Typical bugs in physical simulation are hard to find! • Complex code path.
Dynamic Execution Tracing of Physical Simulations
Jonathan Cohen
The Motivation
• • • Typical bugs in physical simulation are
hard to find
!
Complex code path & data flow gdb/printf ill-suited to the task – where's the breakpoint go? Insert complex debugging routines into the code?
• Need: trace aggregate data flow, gather statistics, look for anomalies, profiling, etc.
• Want: programmable, no recompiling, minimal impact Jonathan Cohen SIGGRAPH 2007 San Diego
Anatomy of an sstrace Script
• A script is made of probes triggered by name – like breakpoint, MODULE:FUNCTION:EVENT or MODULE:CLASS@METHOD:EVENT Jonathan Cohen SIGGRAPH 2007 San Diego
Examples of probe names
• • • • • sim:IncompressibleSolver@Advance:enter sim:IncompressibleSolver@*:enter sim:*:enter sim:PoissonSolver@Solve:iterations sys:main:enter Jonathan Cohen SIGGRAPH 2007 San Diego
Anatomy of an sstrace Script
• Following each probe is a block of code that is executed when probe is hit } MODULE:FUNCTION:EVENT { command -option arg -option arg command -option arg -option arg Jonathan Cohen SIGGRAPH 2007 San Diego
Some Commands
• • • • • print – display text to a log file timer – start, stop, pause a stopwatch histogram – add sample points, display indent – set indentation level of print out counters – basic math Jonathan Cohen SIGGRAPH 2007 San Diego
Anatomy of an sstrace Script
• Command arguments can reference variables } MODULE:FUNCTION:EVENT { print $TOTAL_COST counter -name TOTAL_COST -add $ARG0 Jonathan Cohen SIGGRAPH 2007 San Diego
Special Variables
• • • Any timer can be read as variable ( $total_time ) Arguments passed from code ( $ARG0 , $ARG1 , etc.) Other special variables ( $TIME , $PROBE , $PROCESSMEM , etc.) Jonathan Cohen SIGGRAPH 2007 San Diego
Example: Execution Stack Tracing
} { *:*:enter print -var $PROBEBASE indent -add 2 } { *:*:exit indent -add -2 sim:SphereSim@step sim:SphereWorldBase@AddParticleSim sim:SphereWorldBase@AddParticleSim sim:ContSphereSolverGuendelman@Advance sim:ContSphereSolverGuendelman@TakeStep sim:ContSphereSolverGuendelman@DoCollisionImpulses sim:ContSphereMultiCollision@Insert sim:ContSphereUniformGridCollision@Insert sim:ContSphereUniformGridCollision@Insert sim:ContSphereUniformGridCollision@GetCollisions sim:ContSphereUniformGridCollision@GetCollisions sim:ContSphereSolverGuendelman@DoCollisionImpulses sim:ContSphereUniformGridCollision@GetCollisions sim:ContSphereUniformGridCollision@GetCollisions
Example: Analyze FluidSim Timing
} sim:FluidSim@step:enter { timer -reset mytimer timer -start mytimer } sim:FluidSim@step:exit { histogram -name myhist -add $mytimer } sys:main:exit { histogram -print myhist Jonathan Cohen SIGGRAPH 2007 San Diego
Example: Sphere-Sphere collision
• Complex collision data structure: – KD-Tree – Leaf nodes are either flat lists or uniform grids – Heuristic recursively decides whether to make leaf (which type?) or keep splitting – How does the heuristic work in practice?
Jonathan Cohen SIGGRAPH 2007 San Diego
Video – First spheresim
Jonathan Cohen SIGGRAPH 2007 San Diego
Trace Output
FRAME 240 ------------------------- Type:
Type:ContSphereUniformGridCollision (X,Y,Z) = 8,13,13 efficiency 60.5769
Acceleration data structure memory usage: 122812 Total memory usage: 3.03354e+08 Jonathan Cohen SIGGRAPH 2007 San Diego
Per-Frame Callback
} { dem:*SphereSim@step:enter print -msg "\nFRAME " -var $ARG0 print -msg "--------------------------\n" FRAME 240 ------------------------- Type:
Type:ContSphereUniformGridCollision (X,Y,Z) = 8,13,13 efficiency 60.5769
Acceleration data structure memory usage: 122812 Total memory usage: 3.03354e+08 Jonathan Cohen SIGGRAPH 2007 San Diego
Memory Statistics
{ dem:*SphereWorld@MakeAccelValid:memusage print -msg "Acceleration data structure memory usage: " -var $ARG0 } print -msg "Total memory usage: " -var $PROCESSMEM FRAME 240 ------------------------- Type:
Type:ContSphereUniformGridCollision (X,Y,Z) = 8,13,13 efficiency 60.5769
Acceleration data structure memory usage: 122812 Total memory usage: 3.03354e+08 Jonathan Cohen SIGGRAPH 2007 San Diego
Tree Structure
} { dem:*SphereMultiCollision@Insert:child?type
print -msg "Type:" -var $ARG0 } { dem:*SphereMultiCollision@Insert:enter indent -add 2 } { dem:*SphereMultiCollision@Insert:exit indent -add -2 FRAME 240 ------------------------- Type:
Type:ContSphereUniformGridCollision (X,Y,Z) = 8,13,13 efficiency 60.5769
Acceleration data structure memory usage: 122812 Total memory usage: 3.03354e+08 Jonathan Cohen SIGGRAPH 2007 San Diego
Uniform Grid Statistics
{ } } { dem:*SphereUniformGridCollision@Insert:dimension print -msg " (X,Y,Z) = " -var $ARG0, $ARGV1, $ARGV2 dem:*SphereUniformGridCollision@Insert:efficiency print -msg " efficiency " -var $ARG0 FRAME 240 ------------------------- Type:
Type:ContSphereUniformGridCollision (X,Y,Z) = 8,13,13 efficiency 60.5769
Acceleration data structure memory usage: 122812 Total memory usage: 3.03354e+08 Jonathan Cohen SIGGRAPH 2007 San Diego
Video – second spheresim
Jonathan Cohen SIGGRAPH 2007 San Diego
Trace Output – Second try
FRAME 240 ------------------------- Type:
Type:ContSphereUniformGridCollision (X,Y,Z) = 41, 440, 62 efficiency 0.164151
Acceleration data structure memory usage: 2.86844e+07 Total memory usage: 3.25038e+08 Jonathan Cohen SIGGRAPH 2007 San Diego
Trace Output – Second try
FRAME 240 ------------------------- Type:
Type:ContSphereUniformGridCollision (X,Y,Z) = 41, 440, 62 efficiency 0.164151
Acceleration data structure memory usage: Total memory usage: 3.25038e+08 2.86844e+07 Jonathan Cohen SIGGRAPH 2007 San Diego
Found a bug in the Heuristic!
• • • Splitting threshold was set so that it could never succeed Code was never splitting Validate (with another sstrace script): – cumulative time: 107.553 sec (old) Jonathan Cohen SIGGRAPH 2007 San Diego
Found a bug in the Heuristic!
• • • Splitting threshold was set so that it could never succeed Code was never splitting Validate (with another sstrace script): – cumulative time: 107.553 sec (old) – cumulative time: 82.6091 sec (new) Jonathan Cohen SIGGRAPH 2007 San Diego
Trace Output – Third try
Type:
Type:ContSphereMultiCollision Type:ContSphereUniformGridCollision (X,Y,Z) = 32, 18, 24 efficiency 8.99161
Type:ContSphereMultiCollision Type:ContSphereUniformGridCollision (X,Y,Z) = 26, 150, 20 efficiency 0.387179
Type:ContSphereMultiCollision Type:ContSphereMultiCollision Type:ContSphereBruteForceCollision Type:ContSphereBruteForceCollision Type:ContSphereMultiCollision Type:ContSphereBruteForceCollision Type:ContSphereBruteForceCollision Acceleration data structure memory usage: 5.63038e+06 Total memory usage: 3.10231e+08 Jonathan Cohen SIGGRAPH 2007 San Diego
sstrace Run-Time
• • • • In static constructor, loads sstrace script based on environment variable Parse each probe, build master list of active probes and stores pre-parsed commands Each probe associated with command list Commands triggered at run-time Jonathan Cohen SIGGRAPH 2007 San Diego
Implementation
• • • Triggers are C++ macros, may be disabled with compile-time option Total overhead for probes ~5% Probe binding during static constructor – Pro: minimize overhead when probes disabled – Con: Can't change trace script after program launch Jonathan Cohen SIGGRAPH 2007 San Diego
Implementation
#define T_PROBE_FUNCTION1(BASENAME, ARG0) \ static THookToProbe *__hook = TInitializeProbe(BASENAME); \ TProbeFunctionRef __probe_function; \ if (__hook) __probe_function = \ new TProbeFunction(__hook, TDataList(ARG0)) } FluidSim::Step(float dt) { T_PROBE_FUNCTION1(“sim:FluidSim@Step”, dt); ...
Jonathan Cohen SIGGRAPH 2007 San Diego
Implementation
#define T_PROBE_FUNCTION1(BASENAME, ARG0) \ static THookToProbe *__hook = TInitializeProbe(BASENAME); \ TProbeFunctionRef __probe_function; \ if (__hook) __probe_function = \ new TProbeFunction(__hook, TDataList(ARG0)) • __hook is bound statically • If BASENAME is never referenced in the script, TInitializeProbe returns NULL Jonathan Cohen SIGGRAPH 2007 San Diego
Implementation
#define T_PROBE_FUNCTION1(BASENAME, ARG0) \ static THookToProbe *__hook = TInitializeProbe(BASENAME); \ TProbeFunctionRef __probe_function; \ if (__hook) __probe_function = \ new TProbeFunction(__hook, TDataList(ARG0)) • TProbeFunctionRef is a smart pointer • Basically like std::auto_ptr Jonathan Cohen SIGGRAPH 2007 San Diego
Implementation
#define T_PROBE_FUNCTION1(BASENAME, ARG0) \ static THookToProbe *__hook = TInitializeProbe(BASENAME); \ TProbeFunctionRef __probe_function; \ if (__hook) __probe_function = \ new TProbeFunction(__hook, TDataList(ARG0)) • Since __hook is bound statically, one test per function call • TProbeFunction triggers “enter” and “exit” probes in its constructor and destructor • Passes ARG0 down to the sstrace run-time as $ARG0 Jonathan Cohen SIGGRAPH 2007 San Diego
Related Work
• Solaris DTRACE – Same concept, but probes operate at kernel level (e.g. break on file IO, thread start, timers, etc.) – DTRACE does everything sstrace can do & more • Aspect Oriented Programming (AOP) – “aspects” not “objects” - dynamic emergent entities – “code weaver” interleaves aspects with rest of code Jonathan Cohen SIGGRAPH 2007 San Diego
Future
• • • Get a real interpreter Hook up 2D/3D visualization tools Allow control to pass to user (like gdb breakpoint) for interactive queries Jonathan Cohen SIGGRAPH 2007 San Diego
An idea...
• • What if this were a standard library?
All 3 rd party applications could use the same trace language • Maybe Sun DTRACE team will do this? – User-level DTRACE for compatibility with non Solaris/BSD applications Jonathan Cohen SIGGRAPH 2007 San Diego
Thanks
• • • Entire Sandstorm development team
Spider-Man 3
sand team DTRACE team for the idea Jonathan Cohen SIGGRAPH 2007 San Diego