We can see the sequence and depth of calls. From the sandbox for instance:
./test --trace "*" --out "trace.log"
Will give us this in the trace.log:
T 17:58:05.843859 0x1107d25c0 main >main Line:23
T 17:58:05.844466 0x1107d25c0 main . Going to call APPlocalFunction
T 17:58:05.844501 0x1107d25c0 main . >APPlocalFunction Line:12
T 17:58:05.844549 0x1107d25c0 main . . About to print hello world...
T 17:58:05.844590 0x1107d25c0 main . . Printed hello world!
T 17:58:05.844625 0x1107d25c0 main . <APPlocalFunction
T 17:58:05.844666 0x1107d25c0 main . Creating Foo object
T 17:58:05.844701 0x1107d25c0 APPfoo . >APPfoo::APPfoo Line:10 this=0x7ffee9b9d7d0
T 17:58:05.844756 0x1107d25c0 APPfoo . <APPfoo::APPfoo
T 17:58:05.844798 0x1107d25c0 main . About to call run on Foo
T 17:58:05.844832 0x1107d25c0 APPfoo . >APPfoo::run Line:17 this=0x7ffee9b9d7d0
T 17:58:05.844889 0x1107d25c0 APPfoo . . Value = Rabbit, Count = 5
T 17:58:05.844924 0x1107d25c0 APPfoo . . i = 0
T 17:58:05.844960 0x1107d25c0 APPfoo . . i = 1
T 17:58:05.844995 0x1107d25c0 APPfoo . . i = 2
T 17:58:05.845029 0x1107d25c0 APPfoo . . i = 3
T 17:58:05.845064 0x1107d25c0 APPfoo . . i = 4
T 17:58:05.845104 0x1107d25c0 APPfoo . . Dump= (size=35)
52 61 62 62 69 74 0A 52 Rabb it.R
61 62 62 69 74 0A 52 61 abbi t.Ra
62 62 69 74 0A 52 61 62 bbit .Rab
62 69 74 0A 52 61 62 62 bit. Rabb
69 74 0A it.
T 17:58:05.845140 0x1107d25c0 APPfoo . <APPfoo::run
T 17:58:05.845182 0x1107d25c0 main . All done!
T 17:58:05.845217 0x1107d25c0 APPfoo . >APPfoo::~APPfoo Line:13 this=0x7ffee9b9d7d0
T 17:58:05.845271 0x1107d25c0 APPfoo . <APPfoo::~APPfoo
T 17:58:05.845326 0x1107d25c0 main <mai
We can see the entry into the APPlocalFunction and coming back. Likewise into the APPfoo object.
This comes from using the BAS_FUNCTION macro and the BAS_METHOD macro for methods.