doubt about log of LuaJIT's jit.v module

[tweyseo]

i notice the comment about side traces in jit/v.lua:

Side traces also show the parent trace number and the exit number where they are attached to in parentheses.

i don't quite understand "the exit number where they are attached to", what does the "exit number" actually mean?

like code below:

local v = require("jit.v")

v.on("t1.log")

local a = { 1, 2, 3, 4 }

for i = 1, 100 do

    for i = 1, 100 do

        a[1] = i

    end

    a[2] = "1end2begin"

    for i = 1, 100 do

        a[2] = i

    end

    a[3] = "2end3begin"

    for i = 1, 100 do

        a[3] = i

    end

    

    a[4] = "3end4begin"

    for i = 1, 100 do

        a[4] = i

    end

    a[1] = "4end1begin"

end

and it's trace log:

[TRACE   1 t1.lua:5 loop]

[TRACE   2 t1.lua:10 loop]

[TRACE   3 t1.lua:15 loop]

[TRACE   4 t1.lua:20 loop]

[TRACE   5 (1/3) t1.lua:9 -> 2]

[TRACE   6 (2/3) t1.lua:14 -> 3]

[TRACE   7 (3/3) t1.lua:19 -> 4]

[TRACE   8 (4/3) t1.lua:24 -> 1]

what does the "exit number" actually mean?

And when i use this tool to analyze my lua code, i met:

[TRACE --- re.lua:209 -- leaving loop in root trace at re.lua:247]
[TRACE --- hash.lua:74 -- inner loop in root trace at re.lua:210]
[TRACE --- index.lua:22 -- inner loop in root trace at re.lua:210]

this log means trace abort too? and how could i resolve them? Like in line 2, should i check hash.lua:74 or re.lua:210 ?

[Thibault Charbonnier]

Hi,

What the documentation refers to as the "exit number" is the snapshot
number LuaJIT uses when restoring the C stack from the JIT registers.

Let's dump the bytecode with the following:

require("jit.dump").on("is")

Where the 'i' argument prints the IR, and 's' the snapshot maps[1].
We'll see 8 traces and their respective IR in the stdout output. Let's
take a look at two of them (apologies in advance for my mail client may
truncate lines):

---- TRACE 1 IR
.... SNAP #0 [ ---- ]
0001 int SLOAD #6 CI
0002 > tab SLOAD #1 T
0003 int FLOAD 0002 tab.asize
0004 > int ABC 0003 +1
0005 p32 FLOAD 0002 tab.array
0006 p32 AREF 0005 +1
0007 tab FLOAD 0002 tab.meta
0008 > tab EQ 0007 NULL
0009 num CONV 0001 num.int
0010 num ASTORE 0006 0009
0011 + int ADD 0001 +1
.... SNAP #1 [ ---- ---- ---- ---- ---- ---- ]
0012 > int LE 0011 +100
.... SNAP #2 [ ---- ---- ---- ---- ---- ---- 0011 ---- ----
0011 ]
0013 ------ LOOP ------------
0014 num CONV 0011 num.int
0015 num ASTORE 0006 0014
0016 + int ADD 0011 +1
.... SNAP #3 [ ---- ---- ---- ---- ---- ---- ]
0017 > int LE 0016 +100
0018 int PHI 0011 0016
---- TRACE 1 stop -> loop


[... other traces ...]


---- TRACE 5 start 1/3 jit.lua:11
---- TRACE 5 IR
.... SNAP #0 [ ---- ---- ---- ---- ---- ---- ]
0001 > tab SLOAD #1 T
0002 int FLOAD 0001 tab.asize
0003 > int ABC 0002 +2
0004 p32 FLOAD 0001 tab.array
0005 p32 AREF 0004 +2
0006 tab FLOAD 0001 tab.meta
0007 > tab EQ 0006 NULL
0008 str ASTORE 0005 "1end2begin"
0009 nil TBAR 0001
.... SNAP #1 [ ---- ---- ---- ---- ---- ---- +1 +100 +1
+1 ]
---- TRACE 5 stop -> 2


The part that interests you here is "TRACE 5 start 1/3". The first
number (1) indicates the parent trace number as you pointed out, and the
second one (3) is the "exit number". What this means is that this
sidetrace was created from snapshot #3 of TRACE 1. See this line in TRACE 1:

.... SNAP #3 [ ---- ---- ---- ---- ---- ---- ]

The JIT compiler saved a snapshot indicating that no registers should be
changed when exiting back to the interpreter. The following instruction:

0017 > int LE 0016 +100

is a guard instruction, and in case of failure, the JIT will be
instructed to restore the previous snapshot (#3 in this case). This
instruction is your loop's exit-condition. When 'i' reaches 100, this
write guard will indeed fail, and the JIT must restore the previous
snapshot before moving on.

Regarding the second part of your question, you may have already had a
look at this part of the documentation[2]. It may be so that the loop in
question isn't worth it for the JIT to kick-in (e.g. it is falling back
to interpreter mode too quickly), so my guess is that it may eventually
be blacklisted, since the interpreter would still be faster than
constantly interpreting and attempting tracing. Since this is in re.lua
I suppose that it may be because your regex (or subject) is simple
enough that it does not warrant a lot of iterations in whatever loop is
being executed? We'd have to see the code to be able to tell.

Best,
Thibault

[1]: https://github.com/LuaJIT/LuaJIT/blob/master/src/jit/dump.lua
[2]: https://github.com/LuaJIT/LuaJIT/blob/master/src/jit/v.lua#L47-L49

[tweyseo]

thanks very much for your answer.

For my first question:

in my opinion, the sidetrace was a branch code path of the corresponding trace. and with your

explanation, i see the snapshot:

1.sidetrace was created from snapshot;

(the snapshot here means it was taken before the code path of a trace was branched, right?)

2.the registers should be changed according to the snapshot when the LuaJIT fell back to

interpreter from compiler;

(but a trace can contain many snapshots, so the registers will be changed according to all the

snapshots in a trace, right?)

3.there was a guard instruction next to each snapshot, and in case of failure, the LuaJIT will be 

instructed to restore the previous snapshot.

(the failure here meas the LuaJIT fell back to interpreter from compiler? ulteriorly, a trace jump

to another trace(sidetrace) must fall back to interpreter from compiler? if so, does it contradicts

point 2 which pointed out the registers will be changed according to all the snapshots in a trace

when fallback?)

For the second question:

here is the minimal code:

  1 local random = math.random

  2 local split = require("ngx.re").split

  3 local v = require("jit.v")

  4 v.on("testTrace.log")

  5 

  6 local function f(path)

  7     local m, err = split(path, "/", "jo")

  8     if err then

  9         error(err)

 10     end

 11 

 12     return #m

 13 end

 14 

 15 local pathList = {

 16     "/test1/test2/test3/test4/test5",

 17     "/test1/test2/test3/test4",

 18     "/test1/test2/test3",

 19     "/test1/test2",

 20     "/test1"

 21 }

 22 

 23 local max, len = 10e1, #pathList

 24 for _ = 1, max do

 25     f(pathList[random(1, len)])

 26 end

and it's trace log:

[TRACE   1 lrucache.lua:76 loop]

[TRACE   2 re.lua:209 loop]

[TRACE   3 (2/13) re.lua:229 -> 2]

[TRACE --- t.lua:24 -- inner loop in root trace at re.lua:210]

[TRACE   4 (2/1) re.lua:59 -> 2]

[TRACE   5 (2/28) re.lua:229 -> 2]

[TRACE   6 (3/0) re.lua:229 -> 2]

[TRACE   7 (2/18) re.lua:59 -> 2]

[TRACE   8 (4/4) re.lua:264 -> 2]

how do i analyze [TRACE --- t.lua:24 -- inner loop in root trace at re.lua:210]?

and thank you again!

Tweyseo