Havlak crash

[vext01]

Today's yk and yklua:

$ ~/research/yklua/src/lua harness.lua Havlak 1 150
Starting Havlak benchmark ...
/home/vext01/research/yklua/src/lua: ./havlak.lua:498: attempt to index a nil value (local 'self')
stack traceback:
        ./havlak.lua:498: in field 'new'
        ./havlak.lua:411: in method 'find_loops'
        ./havlak.lua:606: in method 'find_loops'
        ./havlak.lua:569: in method 'main'
        ./havlak.lua:623: in function 'havlak.inner_benchmark_loop'
        harness.lua:49: in method 'measure'
        harness.lua:60: in method 'do_runs'
        harness.lua:43: in method 'run_benchmark'
        harness.lua:97: in main chunk
        [C]: in ?

• release mode build
• non-deterministic crash
• unable to test with YKD_OPT=0 as another bug currently triggers.

This is the most reduced test I've managed so far:

if A then
else
	E = function(G)
		I = {}
		I.G = G
		return I
	end
end
F = {}
do
	H = 10
	function F.F()
		I = {
			A = 1,
		}
		return setmetatable(I, {
			__index = F,
		})
	end
	function F:D(F)
		if F == G then
			return
		end
		return self.E[F]
	end
	function F:J(A)
		if G == J then
			F.E = E(H)
			local G
			for A = 1, F.E.G do
			end
		end
		F.E[self.A] = A
	end
	function F:K(A)
		for B = self.A, self.A do
			A()
		end
	end
end
C = {}
do
	function C.F()
		I = {
			I = F.F(),
		}
		return setmetatable(I, {
			__index = C,
		})
	end
	function C:A(A)
		self.I:J()
	end
end
K = {}
do
	function K.F(I)
		A = I:I()
		A:A()
		A:A()
	end
end
I = {}
do
	function I.F()
		setmetatable(K, {
			__index = I,
		})
	end
	function I:I()
		if F:D() then
		else
			B = C.F()
		end
		return B
	end
end
D = {}
do
	function D.F()
		I = {
			E = F.F(),
		}
		return setmetatable(I, {
			__index = D,
		})
	end
	function D:A()
		do
			A.I:K(function(G)
				local G
				if 0 then
					if 0 then
						F:D(1):J()
					end
				end
			end)
		end
	end
	function D:C()
		if 0 then
			self.E:J(F.F())
		end
		self:A()
	end
end
A = {}
do
	function A.F()
		I.F()
		I = {}
		return setmetatable(I, {
			__index = A,
		})
	end
	function A:E()
		K.F(K)
		return H + 1
	end
	function A:J()
		K.F(K)
	end
	function A:D()
		do
			self:J()
		end
	end
	function A:I()
		self:D()
		H = self:E()
	end
	function A:G()
		self:A(H)
		do
			self:C()
		end
	end
	function A:A(I)
		for _ = 0, H do
			for _ = 0, I do
				for _ = 0, I do
					self:I()
				end
			end
		end
	end
	function A:C()
		D.F():C()
	end
end
B = {}
do
	function B:I()
		A.F():G()
	end
end
B:I()

This reduced test will fail deterministically no matter what you set YKD_SERIALISE_COMPILATION to.

[vext01]

With ykjit/ykllvm#226 applied, I've instrumented the interpreter with a print statement that shows what bytecodes are executed and diffed the output from the above test unjitted and jitted:

--- log.vanilla	2025-02-11 13:19:39.590391228 +0000
+++ log.yk	2025-02-11 13:18:18.714655663 +0000
 ...
 debug_bytecode: count=1794, pc=21, opcode=RETURN0
 debug_bytecode: count=1795, pc=7, opcode=RETURN0
+yk-jit-event: execute-side-trace
 debug_bytecode: count=1796, pc=6, opcode=FORLOOP
-debug_bytecode: count=1797, pc=7, opcode=RETURN0
-debug_bytecode: count=1798, pc=5, opcode=RETURN0
-debug_bytecode: count=1799, pc=8, opcode=RETURN0
-debug_bytecode: count=1800, pc=5, opcode=RETURN0
-debug_bytecode: count=1801, pc=4, opcode=RETURN0
-debug_bytecode: count=1802, pc=5, opcode=RETURN0
-debug_bytecode: count=1803, pc=92, opcode=RETURN
+yk-jit-event: deoptimise
+debug_bytecode: count=1797, pc=6, opcode=FORLOOP
+debug_bytecode: count=1798, pc=4, opcode=MOVE
+debug_bytecode: count=1799, pc=5, opcode=CALL
+debug_bytecode: count=1800, pc=0, opcode=LOADNIL
+debug_bytecode: count=1801, pc=1, opcode=GETTABUP
+debug_bytecode: count=1802, pc=2, opcode=SELF
+debug_bytecode: count=1803, pc=3, opcode=LOADI
+debug_bytecode: count=1804, pc=4, opcode=CALL
+debug_bytecode: count=1805, pc=0, opcode=GETTABUP
+debug_bytecode: count=1806, pc=1, opcode=EQ
+debug_bytecode: count=1807, pc=4, opcode=GETFIELD
+debug_bytecode: count=1808, pc=5, opcode=GETTABLE
+debug_bytecode: count=1809, pc=6, opcode=RETURN1
+debug_bytecode: count=1810, pc=5, opcode=SELF
+/home/vext01/research/yklua/src/lua: havlak.1594.lua:94: attempt to index a nil value
+stack traceback:
+	havlak.1594.lua:94: in local 'A'
+	havlak.1594.lua:37: in method 'K'
+	havlak.1594.lua:90: in method 'A'
+	havlak.1594.lua:104: in method 'C'
+	havlak.1594.lua:143: in method 'C'
+	havlak.1594.lua:130: in method 'G'
+	havlak.1594.lua:149: in method 'I'
+	havlak.1594.lua:152: in main chunk
+	[C]: in ?

This shows that program semantics deviate when executing a side trace.

I'm now getting shrinkray find a smaller program where the executed bytecodes still differ. Maybe this will give us a smaller program than above.

EDIT: sadly it was unable to make the program smaller.

[ptersilie]

This could still be a deopt problem. Note how it only deviates after deopt.

[ltratt]

I agree: that seems almost certainly to be a deopt problem given the clear deviation one can see in the diff. Which is both annoying and good, because we've got a strong lead as to what to look at: presumably if we check gdb at the relevant guard in the JITed and un-JITed case we should be able to see a register / memory location being set differently?