Dynamic Execution Tracing of Physical Simulations

1
Dynamic Execution Tracing of Physical Simulations
Jonathan Cohen
2
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

3
Anatomy of an sstrace Script

• A script is made of probes like breakpoint,
  triggered by name

MODULEFUNCTIONEVENT or MODULECLASS_at_METHODEV
ENT
4
Examples of probe names

• simIncompressibleSolver_at_Advanceenter
• simIncompressibleSolver_at_enter
• simenter
• simPoissonSolver_at_Solveiterations
• sysmainenter

5
Anatomy of an sstrace Script

• Following each probe is a block of code that is
  executed when probe is hit

MODULEFUNCTIONEVENT command -option arg
-option arg command -option arg -option arg
6
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

7
Anatomy of an sstrace Script

• Command arguments can reference variables

MODULEFUNCTIONEVENT print TOTAL_COST counte
r -name TOTAL_COST -add ARG0
8
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.)

9
Example Execution Stack Tracing
simSphereSim_at_step simSphereWorldBase_at_AddPartic
leSim simSphereWorldBase_at_AddParticleSim
simContSphereSolverGuendelman_at_Advance
simContSphereSolverGuendelman_at_TakeStep
simContSphereSolverGuendelman_at_DoCollisionImpulses
simContSphereMultiCollision_at_Insert
simContSphereUniformGridCollision_at_Insert
simContSphereUniformGridCollision_at_Insert
simContSphereUniformGridCollision_at_GetColli
sions simContSphereUniformGridCollision_at_G
etCollisions simContSphereSolverGuendelman_at_
DoCollisionImpulses simContSphereUniformG
ridCollision_at_GetCollisions
simContSphereUniformGridCollision_at_GetCollisions lt
snipgt
enter print -var PROBEBASE indent
-add 2 exit indent -add -2
10
Example Analyze FluidSim Timing
simFluidSim_at_stepenter timer -reset
mytimer timer -start mytimer simFluidSim_at_step
exit histogram -name myhist -add mytimer
sysmainexit histogram -print myhist
11
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?

12
Video First spheresim
13
Trace Output
FRAME 240 -------------------------- Type lttop
levelgt TypeContSphereUniformGridCollision
(X,Y,Z) 9,14,15 efficiency 46.8783
TypeContSphereUniformGridCollision (X,Y,Z)
8,13,13 efficiency 60.5769 Acceleration data
structure memory usage 122812 Total memory
usage 3.03354e08
14
Per-Frame Callback
FRAME 240 -------------------------- Type lttop
levelgt TypeContSphereUniformGridCollision
(X,Y,Z) 9,14,15 efficiency 46.8783
TypeContSphereUniformGridCollision (X,Y,Z)
8,13,13 efficiency 60.5769 Acceleration data
structure memory usage 122812 Total memory
usage 3.03354e08
demSphereSim_at_stepenter print -msg "\nFRAME
" -var ARG0 print -msg "-----------------------
---\n"
15
Memory Statistics
FRAME 240 -------------------------- Type lttop
levelgt TypeContSphereUniformGridCollision
(X,Y,Z) 9,14,15 efficiency 46.8783
TypeContSphereUniformGridCollision (X,Y,Z)
8,13,13 efficiency 60.5769 Acceleration data
structure memory usage 122812 Total memory
usage 3.03354e08
demSphereWorld_at_MakeAccelValidmemusage
print -msg "Acceleration data structure memory
usage " -var ARG0 print -msg "Total memory
usage " -var PROCESSMEM
16
Tree Structure
demSphereMultiCollision_at_Insertchild?type
print -msg "Type" -var ARG0 demSphereMultiC
ollision_at_Insertenter indent -add
2 demSphereMultiCollision_at_Insertexit
indent -add -2
FRAME 240 -------------------------- Type lttop
levelgt TypeContSphereUniformGridCollision
(X,Y,Z) 9,14,15 efficiency 46.8783
TypeContSphereUniformGridCollision (X,Y,Z)
8,13,13 efficiency 60.5769 Acceleration data
structure memory usage 122812 Total memory
usage 3.03354e08
17
Uniform Grid Statistics
FRAME 240 -------------------------- Type lttop
levelgt TypeContSphereUniformGridCollision
(X,Y,Z) 9,14,15 efficiency 46.8783
TypeContSphereUniformGridCollision (X,Y,Z)
8,13,13 efficiency 60.5769 Acceleration data
structure memory usage 122812 Total memory
usage 3.03354e08
demSphereUniformGridCollision_at_Insertdimension
print -msg " (X,Y,Z) " -var
ARG0, ARGV1, ARGV2 demSphereUniformGridCol
lision_at_Insertefficiency print -msg "
efficiency " -var ARG0
18
Video second spheresim
19
Trace Output Second try
FRAME 240 -------------------------- Type lttop
levelgt TypeContSphereUniformGridCollision
(X,Y,Z) 23, 38, 87 efficiency 3.92304
TypeContSphereUniformGridCollision (X,Y,Z)
41, 440, 62 efficiency 0.164151 Acceleration
data structure memory usage 2.86844e07 Total
memory usage 3.25038e08
20
Trace Output Second try
FRAME 240 -------------------------- Type lttop
levelgt TypeContSphereUniformGridCollision
(X,Y,Z) 23, 38, 87 efficiency 3.92304
TypeContSphereUniformGridCollision (X,Y,Z)
41, 440, 62 efficiency 0.164151 Acceleration
data structure memory usage 2.86844e07 Total
memory usage 3.25038e08
21
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)

22
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)

23
Trace Output Third try
Type lttop levelgt TypeContSphereUniformGridColl
ision (X,Y,Z) 23, 38, 87 efficiency
3.96249 TypeContSphereMultiCollision
TypeContSphereUniformGridCollision (X,Y,Z)
32, 18, 24 efficiency 8.99161
TypeContSphereMultiCollision
TypeContSphereUniformGridCollision
(X,Y,Z) 26, 150, 20 efficiency 0.387179
TypeContSphereMultiCollision
TypeContSphereMultiCollision
TypeContSphereBruteForceCollision
TypeContSphereBruteForceCollision
TypeContSphereMultiCollision
TypeContSphereBruteForceCollision
TypeContSphereBruteForceCollision Acceleration
data structure memory usage 5.63038e06 Total
memory usage 3.10231e08
24
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

25
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

26
Implementation
define T_PROBE_FUNCTION1(BASENAME, ARG0) \
static THookToProbe __hook TInitializeProbe(BAS
ENAME) \ TProbeFunctionRef __probe_function
\ if (__hook) __probe_function \ new
TProbeFunction(__hook, TDataList(ARG0))
FluidSimStep(float dt) T_PROBE_FUNCTION1(s
imFluidSim_at_Step, dt) ...
27
Implementation
define T_PROBE_FUNCTION1(BASENAME, ARG0) \
static THookToProbe __hook TInitializeProbe(BAS
ENAME) \ 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

28
Implementation
define T_PROBE_FUNCTION1(BASENAME, ARG0) \
static THookToProbe __hook TInitializeProbe(BAS
ENAME) \ TProbeFunctionRef __probe_function
\ if (__hook) __probe_function \ new
TProbeFunction(__hook, TDataList(ARG0))

• TProbeFunctionRef is a smart pointer
• Basically like stdauto_ptr

29
Implementation
define T_PROBE_FUNCTION1(BASENAME, ARG0) \
static THookToProbe __hook TInitializeProbe(BAS
ENAME) \ 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

30
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

31
Future

• Get a real interpreter
• Hook up 2D/3D visualization tools
• Allow control to pass to user (like gdb
  breakpoint) for interactive queries

32
An idea...

• What if this were a standard library?
• All 3rd 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

33
Thanks

• Entire Sandstorm development team
• Spider-Man 3 sand team
• DTRACE team for the idea