Bytecode interpreter (memread / 7) broken?

[fernewelten]

I'm in AGS 3.5, Commit 4191f0e, where I've added a private branch and added my rewritten compiler to debug it.

For this, I'm using a newly created "Empty Game" where the room 1 has the event "Enters room after fade-in" installed (as room_AfterFadeIn).

This is the complete room script:

int room_AfterFadeIn()
{
    int f = 3;
    int g = 5;
    int z = f + 11;
    Display("z = %d", z);
}

This is the Bytecode that my compiler generates for int z = f + 11; in the script given above:

         Disassembled         Bytecodes
00000001 load.sp.offs 12      51 12 
00000002 memread   ax          7  3   
00000003 push   ax            29  3         
00000004 mov    ax,   11       6  3 11
00000005    
00000006 pop    bx            30  4   
00000007 add    bx,   ax      11  4  3       
00000008 mov    bx,   ax       3  4  3 
00000009 load.sp.offs  4      51  4    
00000010 memwrite   ax         8  3 

Running the program yields z = 14, which is correct.

Now change that AGS statement to int z = f + g
Note that the Bytecode has remained exactly the same, except for lines 4 and 5:

00000001 load.sp.offs   12        51 12    
00000002 memread   ax              7  3   
00000003 push   ax                29  3   
00000004 load.sp.offs   12        51  12    
00000005 memread   ax              7  3   
00000006 pop    bx                30  4   
00000007 add    bx,   ax          11  4  3    
00000008 mov    bx,   ax           3  4  3
00000009 load.sp.offs   4         51  4
00000010 memwrite   ax	           8  3	

Surprisingly, running the program yields z=5, which is incorrect.

It seems very much that the value pushed at line 3 (namely, 3) is different from the value popped in line 6 (zero, but should still be 3, of course). I very much suspect that memread ax in line 5 has somehow clobbered the value pushed onto the stack.

This may be related to #869, but I suspect this is a separate issue: I've tried changing lines 3 and 4 into the equivalent lines

00000003 load.sp.offs   8        
00000004 push   ax                

so that the only command between the push ax and the pop bx is now memread ax. I still got z = 5. So it seems that load.sp.offs isn't at fault, but memread is.

---

Is there a good way to debug the Engine?

Currently, I'm running programs by opening the solution AGS.Editor.Full and hitting F5 to open the AGS Editor; then hitting f5 within the Editor to run the program. The debugger will stop at breakpoints set in the compiler, but not at breakpoints set in the Engine. So I can't step through the bytecode emulation to see what it does.

[fernewelten]

For reference, the compiled game.
EmptyTestGame.zip

[ghost]

Is there a good way to debug the Engine?

Currently, I'm running programs by opening the solution AGS.Editor.Full and hitting F5 to open the AGS Editor; then hitting f5 within the Editor to run the program. The debugger will stop at breakpoints set in the compiler, but not at breakpoints set in the Engine. So I can't step through the bytecode emulation to see what it does.

Of course, if you are using MSVS debugger, then you may pass a path to compiled game in Debugging - Command Arguments project setting.

Please note that there is a problem on some systems, supposedly caused by something in Allegro code. It makes mouse and keyboard input lag terribly when breakpoint is hit.
The only solution I found so far is this:

• open Windows registry and find "LowLevelHooksTimeout" parameter. Change it to something very small, like 10 (it's in ms)

[ghost]

@fernewelten , if I use original AGS and compiler I get "z = 8" displayed on screen, as expected.

[ghost]

For the reference, here's the original compiler's bytecode of the line in question (int z = f + g)

load.sp.offs 8
memread ax
push ax
load.sp.offs 8
memread ax
pop bx
add bx, ax
mov bx, ax
mov sp, mar
memwrite ax
add sp, 4

[ghost]

So, if I guess correctly, your compiler allocates new variable on stack before computing its value, while original compiler first computed value then wrote it to stack and advanced stack pointer.

From what I see the main difference is this: original compiler was writing value by doing mov sp, mar which made MAR registry point onto stack, this is where next memwrite ax writes.

Your compiler does load.sp.offs 4 which is supposed to make MAR registry point onto stack as well, and then same memwrite ax.

EDIT: But frankly, I doubt this is what causing trouble, because if it did not work then assigning local variables would be broken, is not it?....
Maybe the source of error is somewhere beyond this assembly snippet?

[fernewelten]

From what I see the main difference is this: original compiler was writing value by doing mov sp, mar which made MAR registry point onto stack, this is where next memwrite ax writes.
Your compiler does load.sp.offs 4 which is supposed to make MAR registry point onto stack as well, and then same memwrite ax.

Yes, that sums it up very well. So the core of the calculation hasn't changed at all, compared to the old compiler.

[ghost]

@fernewelten
I was debugging engine running your compiled script, and I noticed that the byte code is actually different from what you posted:

load.sp.offs 12
memread ax
push ax
load.sp.offs 12
memread ax
pop bx
add bx, ax
mov bx, ax
memread ax <------------------------
load.sp.offs 4
memwrite ax

Notice that extra memread ax, it overwrites 8 in AX with previously read 5.

[fernewelten]

Oh dear. Thanks for the tip.
EDIT:
I've just traced the compiler do Room 1.
It does NOT emit the "memread ax". It definitely emits

pop bx
add bx, ax
mov bx, ax
load.sp.offs 4

The spurious memread ax must somehow come to be after the compiler has emitted its code. But how?

[ghost]

Yes this is very strange. Unfortunatel I must make a break now.
I think there may be several stages where this defect could occur, starting from what compiler actually writes to file, and ending with the engine incorrectly loading or parsing the bytecode.
This could be even something trivial as your game exe having old version of the script remaining from faulty compiler version...

[fernewelten]

Well, I'm going on the hunt now and see where it turns awry.

Thanks a ton for all that help, and in the middle of the night, too. Really, I got the surprise of my life when I booked in that bug report in the wee morning hours and found that it already got its first response half an hour later.

[fernewelten]

So, I've found the issue: something in the compiler had subtly gone out of sync. Ivan's discovery of that spurious additional command was what pointed me to the problem.

I'm still doing some careful additional checks to be on the safe side, but in the meantime I'm assuming the issue to be solved.

[fernewelten]

Please note that there is a problem on some systems, supposedly caused by something in Allegro code. It makes mouse and keyboard input lag terribly when breakpoint is hit.
open Windows registry and find "LowLevelHooksTimeout" parameter. Change it to something very small, like 10 (it's in ms)

I had this problem too. My registry didn't have the key at all, so I added it as a dword under HKEY_CURRENT_USER/Desktop/, and the problem went away after a reboot.

As far as I understand the problem, Allegro hooks some code into the mouse and keyboard handlers. When the debugger halts the execution at a break point, it halts all the threads, so it halts that hooked code in particular, too. So execution never returns from the hooks, in essence blocking mouse and keyboard completely -- until Windows steps in after some time and forces a time-out. It seems that this LowLevelHooksTimeout entry tells Windows to timeout the blocked hooks very soon.