HXCPP Built-in Debugging

The latest version of hxcpp has increased control over how much debugging information is included in the compiled code, as well as some built-in debugging and profiling tools.

Debugging is normally added with the -debug flag to the compiler. This flag turns off compiler optimisation, adds source-line and call-stack tracking and adds additional runtime checks – eg for null pointer access. This is useful for locating problems, but it can make the code run several times slower.

Depending on the application, you may not need all these debugging features. For example, if you do not intend to attach a native debugger, then you probably do not need to turn off compiler optimisations. If you are trying to profile the code, you probably only want the call-stack symbols, but not the other runtime checks. These scenarios are now supported by HXCPP, via compiler defines.

Quick recap: To add a define to the haxe compiler, you can use the “-D DEFINE” syntax on the command line or hxml file, or <haxedef name="DEFINE" /> from an nmml file.

Now, for testing performance, I will be using BunnyMark, and add bunnies until there the a measurable drop in performance. In this case, I added 20000 bunnies to get a frame-rate of about 50fps on my macbook air.

Adding the -debug flag brings the frame-rate down to about 40fps. This is not a huge drop – I guess because the CPU is not that taxed, it the the GPU that is doing more work.

So instead of adding the -debug flag, we can add various defines to achieve the effect we are after.

HXCPP_DEBUG_LINK

Adding this define will keep the symbol tables in the final executable. This is probably not something you want to do in your final release build for external use, but it is something that that is good to have otherwise. This flag will allow you to get meaningful information if you attach your system debugger. Runtime performance hit: none.

DHXCPP_STACK_TRACE

This define will allow you to get a haxe stack trace that includes function names when an exception is thrown, or when the stack is queried directly. There is a small overhead incurred per function call when this is on. Runtime performance hit: very small.

HXCPP_STACK_LINE

This define implies DHXCPP_STACK_TRACE and adds line numbers to the function names. There is additional overhead per line of haxe code, however I had trouble measuring this overhead on the bunnymark – probably because it is not too CPU intensive. Runtime performance hit: small to medium.

HXCPP_CHECK_POINTER

This define explicitly checks pointers for null access and throws an informative exception, rather than just crashing. There is an overhead per member-access. Again, for the bunnymark, it was hard to measure a slowdown. Runtime performance hit: small.

So, these defines can be added without using the -debug flag, which removes the compiler optimisations, which accounts for over 80% of the performance drop.

Built-in Profiler

So where is all the time spent? To answer this question, you can use the built-in profiler. The profiler needs HXCPP_STACK_TRACE, and is started by calling cpp.vm.Profiler.start(filename) from the haxe thread you are interested in. You can call this, say, in response to a button-press, but in this example, I will call it from the mainline. You can provide a log filename, or you can just let it write to stdout. If you use a relative filename in an nme project, the file will be written into the executable directory.

  private static function create()
  {
     cpp.vm.Profiler.start("log.txt");
     Lib.current.addChild (new BunnyMark());
  }

We can then analyse the log. The entries are sorted by total time (including child calls) spent in the routine. The first few are all about 100%, as they look for somewhere to delegate the actual work to. Soon enough, we get to this entry:

Stage::nmeRender 95.60%/0.07%
   DisplayObjectContainer::nmeBroadcast 39.6%
   extern::cffi 60.3%
   (internal) 0.1%


Here the Stage::nmeRender call is almost always active, and is broadcasting an event (the ENTER_FRAME event) for 40% of its time, and calling into cffi (nme c++ render code) for 60% of the time. So we have learnt something already.

You can trace ENTER_FRAME the calls though the event dispatcher until we get to the routine actually in bunnymark:

TileTest::enterFrame 36.55%/8.26%
   Lib::getTimer 0.1%
   Tilesheet::drawTiles 70.2%
   Graphics::clear 6.6%
   DisplayObject::nmeSetY 0.0%
   DisplayObject::nmeSetX 0.0%
   DisplayObject::nmeGetWidth 0.2%
   DisplayObject::nmeGetHeight 0.1%
   DisplayObject::nmeGetGraphics 0.2%
   GC::realloc 0.1%
   (internal) 22.6%

Here the “36.55%/8.26%” means that 35% of the total exe time is spent in this routine, including its children, but only 8% of the total time is spent internally (ie, not in child calls).

And, looking at the drawTiles call:

Tilesheet::drawTiles 25.65%/0.01%
   Graphics::drawTiles 99.9%
   (internal) 0.1%

We see 25% of the total time is spend in the NME Graphics::drawTiles call. So this app spends 60% of the time in drawing routine, and 25% of the time in preparing the draw call. From this, you can assume that it is pretty well optimised!

It is also interesting to note the GC entry:

GC::new 0.17%/0.15%
   GC::collect 12.0%
   (internal) 88.0%


Which is very small, indicating that techniques such as object pooling would have no effect here.

This technique is available on all platforms – you just might have to be a little bit careful about where you write your output file.

Built-in Debugger

The built-in debugger requires you to compile with the HXCPP_DEBUGGER define. Starting the debugger is similar to starting the profiler.

  private static function create()
  {
     new hxcpp.DebugStdio(true);
     Lib.current.addChild (new BunnyMark());
  }

You will note that the “DebugStdio” class is in the hxcpp project, so you will need to add the “-lib hxcpp” command, or via nmml: < haxelib name="hxcpp" />.

The “true” parameter means that the debugger stops as soon as you hit this line. This allows you to set breakpoints etc. Running the above, I get an empty display window (no draw calls have been made yet), and a prompt on the command line:

debug>stopped.
debug>h
help  - print this message
break [file line] - pause execution of one thread [when at certain point]
breakpoints - list breakpoints
delete N - delete breakpoint N
cont  - continue execution
where - print call stack
files - print file list that may be used with breakpoints
vars - print local vars for frame
array limit N - show at most N array elements
mem - print memory usage
collect - run Gc collection
compact - reduce memory usage
exit  - exit programme
bye  - stop debugging, keep running
ok
debug>

Entering “files” shows the input files with indexes 0 to 93. You can use either the filename or file number for setting breakpoints. For example:

debug>break BunnyMark.hx 41

Will set a breakpoint for line 41 on BunnyMark.hx. Currently, you are going to need to have the file handy to look up the line number. So now we want to go back to executing:

debug> c


And immediately, the debugger prints “stopped”. This is because the breakpoint has been hit. To find out where, you can use the “w” command:

debug>stopped.
w
Must break first.
debug>where
*1:FilePos(Method(BunnyMark,addedToStage),BunnyMark.hx,41)
 2:FilePos(Method(Listener,dispatchEvent),neash/events/EventDispatcher.hx,181)
 3:FilePos(Method(EventDispatcher,dispatchEvent),neash/events/EventDispatcher.hx,80)
 4:FilePos(Method(DisplayObject,nmeDispatchEvent),neash/display/DisplayObject.hx,315)
 5:FilePos(Method(DisplayObject,dispatchEvent),neash/display/DisplayObject.hx,198)
 6:FilePos(Method(DisplayObject,nmeOnAdded),neash/display/DisplayObject.hx,458)
 7:FilePos(Method(DisplayObjectContainer,nmeOnAdded),neash/display/DisplayObjectContainer.hx,183)
 8:FilePos(Method(DisplayObject,nmeSetParent),neash/display/DisplayObject.hx,659)
 9:FilePos(Method(DisplayObjectContainer,addChild),neash/display/DisplayObjectContainer.hx,31)
 10:FilePos(Method(BunnyMark,create),BunnyMark.hx,81)
 11:FilePos(Method(BunnyMark,main),BunnyMark.hx,69)
 12:FilePos(Method(Reflect,callMethod),Reflect.hx,55)
 13:FilePos(Method(*,_Function_1_1),ApplicationMain.hx,59)
 14:FilePos(Method(*,_Function_1_1),neash/Lib.hx,75)
 15:FilePos(Method(extern,cffi),/Users/hugh/dev/code.google/hxcpp/src/hx/Lib.cpp,130)
 16:FilePos(Method(Lib,create),neash/Lib.hx,64)
 17:FilePos(Method(Lib,create),nme/Lib.hx,60)
 18:FilePos(Method(ApplicationMain,main),ApplicationMain.hx,39)
ok

The “you must break first” is a little bug in the debugger due to the fact that the break is async. But trying again seems to have fixed this. So here you can see the full call stack. Using the “vars” command shows the local variables, and using the “p” command (short for “print”) shows the values.

debug>vars
[e,this]
ok
debug>p e
nmeIsCancelledNow=false
nmeIsCancelled=false
_type=addedToStage
_target=BunnyMark
_eventPhase=1
_currentTarget=BunnyMark
_cancelable=false
_bubbles=false
type=addedToStage
target=BunnyMark
eventPhase=1
currentTarget=BunnyMark
cancelable=false
bubbles=false
ok
debug>p this
fps=FPS
bg=Background
useHandCursor=false
buttonMode=false
nmeChildren=2 elements
tabChildren=false
numChildren=2
mouseChildren=true
nmeMouseEnabled=true
needsSoftKeyboard=false
moveForSoftKeyboard=false
mouseEnabled=true
doubleClickEnabled=false
nmeScrollRect=(null)
nmeScale9Grid=(null)
nmeParent=neash.display.MovieClip
nmeID=3
nmeGraphicsCache=(null)
nmeFilters=(null)
y=0
x=0
width=580
visible=true
transform=neash.geom.Transform
stage=neash.display.Stage
scrollRect=(null)
scaleY=1
scaleX=1
scale9Grid=(null)
rotation=0
parent=neash.display.MovieClip
opaqueBackground=(null)
nmeHandle=null
name=BunnyMark 3
mouseY=0
mouseX=0
mask=(null)
height=740
graphics=neash.display.Graphics
filters=(empty)
pixelSnapping=NEVER
pedanticBitmapCaching=false
cacheAsBitmap=false
blendMode=NORMAL
alpha=1
nmeTarget=BunnyMark
nmeEventMap=Hash
ok

So now we have a little fun (in a very nerdy sort of way):

debug>set fps.y = 200
ok
debug>cont
running

And you can see that the fps counter has moved down the screen. The more astute reader will notice that the “y” member is actually a “property” and that setting this property has actually caused some haxe code to be run. You can also print the value of a function call to get arbitrary functions to run.
While the code is running you can use “break” to stop it wherever it happens to be.
Using the “exit” command is a quick way out – this can be useful on android when you want to make sure the process is actually dead.

You can jump into a different function on the stack via the "frame" command (notice the "*" has moved), and examine the vars there:

 => frame 17
ok
 => where
 1:FilePos(Method(BunnyMark,addedToStage),BunnyMark.hx,41)
 2:FilePos(Method(Listener,dispatchEvent),neash/events/EventDispatcher.hx,181)
 3:FilePos(Method(EventDispatcher,dispatchEvent),neash/events/EventDispatcher.hx,80)
 4:FilePos(Method(DisplayObject,nmeDispatchEvent),neash/display/DisplayObject.hx,315)
 5:FilePos(Method(DisplayObject,dispatchEvent),neash/display/DisplayObject.hx,198)
 6:FilePos(Method(DisplayObject,nmeOnAdded),neash/display/DisplayObject.hx,458)
 7:FilePos(Method(DisplayObjectContainer,nmeOnAdded),neash/display/DisplayObjectContainer.hx,183)
 8:FilePos(Method(DisplayObject,nmeSetParent),neash/display/DisplayObject.hx,659)
 9:FilePos(Method(DisplayObjectContainer,addChild),neash/display/DisplayObjectContainer.hx,31)
 10:FilePos(Method(BunnyMark,create),BunnyMark.hx,81)
 11:FilePos(Method(BunnyMark,main),BunnyMark.hx,70)
 12:FilePos(Method(Reflect,callMethod),Reflect.hx,55)
 13:FilePos(Method(*,_Function_1_1),ApplicationMain.hx,59)
 14:FilePos(Method(*,_Function_1_1),neash/Lib.hx,75)
 15:FilePos(Method(extern,cffi),/Users/hugh/dev/code.google/hxcpp/src/hx/Lib.cpp,130)
 16:FilePos(Method(Lib,create),neash/Lib.hx,64)
*17:FilePos(Method(Lib,create),nme/Lib.hx,60)
 18:FilePos(Method(ApplicationMain,main),ApplicationMain.hx,39)
ok
 => vars
[icon,title,flags,color,frameRate,height,width,onLoaded]
ok
 => p title
BunnyMark

The command line is all well and good for desktop apps, but it is not much use for mobile apps. To use the debugger on mobile, you can create a debug socket server - the mobile will then connect over WiFi. On your desktop, create and run the hxcpp DdebugTool:

haxe -main hxcpp.DebugTool -lib hxcpp -neko server.n
neko server.n
Waiting for connection on 192.168.0.12:8080

You can see the ip:port that the server is waiting on. Then, back in your code, replace the "DebugStdio" line with a "DebugSocket" line, using the ip:port from the server:

private static function create()
{
   new hxcpp.DebugSocket("192.168.0.12",8080,true);
   Lib.current.addChild (new BunnyMark());
}

And then the operation is exactly the same as before.

The debug code is designed to allow different protocols and backends. It should be possible to replace the code in the hxcpp library with code of your own to present the debug information in any way you like. The "worker" classes are in cpp.vm.Debugger, and you can build your own debugger on top of these.
As a final trick, you can call the debugger functions directly (eg, to always add a breakpoint), or cpp.vm.Debugger.breakBad() (I've been watching too much TV) to allow complex conditions to generate breakpoints, eg:

   if (items.length>0 && !found)
      Debugger.breakBad(); // WTF ?

23 Replies to “HXCPP Built-in Debugging”

    1. There is some experimental support for this via the
      Debugger.setBreak(Debugger.BRK_STEP) and then continue, but I had a few little issues with haxe line numbers, and it is not 100% yet.
      You would need to add a command to DebugBase to test this.

    1. Hi,
      Both ends of the DebugSocket are written in simple haxe. If you wanted the results in JSON, you could extend the hxcpp.DebugSocket object and write your own versions of “showWhere”, “showFiles”, “onPrint” etc. If you wanted the commands in JSON, you could rewrite the parsing in “InputLoop”.
      Hugh

  1. I will support debugging in the next version of our Haxe plugin for IntelliJ IDEA. Now I have some problems with parsing in tricky cases. So It would be nice if better protocol is bundled with hxcpp library 🙂

  2. For the profiler, is it possible to use a absolute file path?
    I’m using it for a NME Android project so I cannot really use a relative path.
    Currently it seems to be ignoring the absolute path and I found the ouput in logcat.

  3. Please for the love of all is good… integrate this debugger with Flash Develop’s interactive debugger. There are so many little incompatibilities that I find between flash and cpp targets, it would help a lot to be able to break code visually 🙂

    1. Hi,
      Personally, I do not have time to do this – but I hope I have provided enough hooks for others to take up this challenge.
      Hugh

  4. I don’t have time to either unfortunately. So gonna have to work with what I got… I got the Server debugger up and running, interfacing with the server from Haxe is super simple, I love it!

    A few notes: Passing true to “inCreateStopped” for DebugSocket’s constructor is not very useful, since we can’t move up or down the call stack, you can’t look at variables in the scope of the object you’re trying to debug (you’re stuck in DebugBase’s constructor). One critical functionality is missing: step. We need to be able to continue executing in code, and examine the behavior of the stack / and keep track of watched vars.

    Is this something you think you could implement?

    My ultimate goal is to connect an Android phone to the debugger. So I can break and debug my Android build. So far I’ve had no luck establishing a connection from the windows host to the android client, even though I forwarded port 8080 through my router. The android and windows targets seem to work exactly the same way, so I’m ok debugging it in windows for now, but it would be nice to get log and perf data from the phone itself.

    Also, it would be sweet if “sendOutput” function was public so I could use this debugger as my main logging mechanism. I got around it by using Reflect, but that’s kinda slow.

    Sorry for posting a shameless plug here… but I just updated my FindFiles Pugin for FD4, and it’s super useful to use with haxe since you can navigate to any file in the haxelib dev directory very quickly. Download it Now!

  5. Looks great..
    As I am as3 developer it would be very helpfull if you can intigrate in flash builder(flex), Excellent editor for as3 language.

  6. So, what’s the likelihood of getting ‘step’ command into the hxcpp debugger? Right now, it’s useful to be able to set a breakpoint and inspect variables, but tricky if you need to explore into nested function calls, or even the next line of code in the current function.

  7. When using the remote socket debugger the break points don’t work. Everything else seems to be working fine, I can break and continue execution, see the list of files and the breakpoints available but the execution does not stop on the break points.

  8. In Flashdevelop in order to be able to see the output window to send commands to the debugger I had to add the following to the project properties, tab “output” in the option “run custom command”: haxelib run nme run “application.nmml” windows -debug
    Either using the remote socket or “new hxcpp.DebugStdio(true)” I could’nt get the breakpoints to work. I have this in the nmml file:

    Am I missing something?

  9. ok found out why it was not working, in Flashdevelop you have to compile with the “Release” version, the “Debugger” version will not work.

Leave a Reply

Your email address will not be published. Required fields are marked *