Another guru to debug

[deimos]

Originally Posted by meynaf

It's located in first code section.

Using https://onlinedisassembler.com/ on the elf file (now attached) shows three trap #7s:

one near the end of Keyboard_Interrupt_ProcessRawKeyCode
one near the end of Keyboard_Interrupt_ProcessRawKeyCodeBuffer
and one at the end of PlayGame

[Edit: The first 2 of these are actually the same, due to inlining]

From the other instructions around it I can see that it's the one in Keyboard_Interrupt_ProcessRawKeyCodeBuffer that gets triggered.

And the dev environment creates a handy assembler file too:

00003f2a <Keyboard_Interrupt_ProcessRawKeyCodeBuffer>:
int Keyboard_Interrupt_ProcessRawKeyCodeBuffer(void) {
    3f2a:	48e7 3f3e      	movem.l d2-d7/a2-a6,-(sp)
    if (keyboard.rawKeyCodeBuffer.length == 0)
    3f2e:	41f9 0000 f124 	lea f124 <keyboard>,a0
    3f34:	3039 0000 f1a4 	move.w f1a4 <keyboard+0x80>,d0
    3f3a:	6700 0180      	beq.w 40bc <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0x192>
    if (keyboard.rawKeyCodeBuffer.length == 0)
    3f3e:	3039 0000 f1a4 	move.w f1a4 <keyboard+0x80>,d0
    3f44:	6700 0176      	beq.w 40bc <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0x192>
    UBYTE rawKeyCode = keyboard.rawKeyCodeBuffer.contents[keyboard.rawKeyCodeBuffer._readIndex];
    3f48:	3039 0000 f1a6 	move.w f1a6 <keyboard+0x82>,d0
    3f4e:	0280 0000 ffff 	andi.l #65535,d0
    3f54:	1030 0800      	move.b (0,a0,d0.l),d0
    keyboard.rawKeyCodeBuffer.length--;
    3f58:	3239 0000 f1a4 	move.w f1a4 <keyboard+0x80>,d1
    3f5e:	5341           	subq.w #1,d1
    3f60:	33c1 0000 f1a4 	move.w d1,f1a4 <keyboard+0x80>
    keyboard.rawKeyCodeBuffer._readIndex++;
    3f66:	3239 0000 f1a6 	move.w f1a6 <keyboard+0x82>,d1
    3f6c:	5241           	addq.w #1,d1
    3f6e:	33c1 0000 f1a6 	move.w d1,f1a6 <keyboard+0x82>
    if (keyboard.rawKeyCodeBuffer._readIndex == RAW_KEY_CODE_BUFFER_MAX_LENGTH)
    3f74:	3239 0000 f1a6 	move.w f1a6 <keyboard+0x82>,d1
    3f7a:	0c41 0080      	cmpi.w #128,d1
    3f7e:	6700 01c4      	beq.w 4144 <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0x21a>
    for (UBYTE rawKeyCode = Keyboard_Interrupt_FetchRawKeyCodeFromBuffer();
    3f82:	0c00 ffff      	cmpi.b #-1,d0
    3f86:	6700 0134      	beq.w 40bc <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0x192>
    3f8a:	3639 0000 f1ae 	move.w f1ae <keyboard+0x8a>,d3
    3f90:	3279 0000 f1b2 	movea.w f1b2 <keyboard+0x8e>,a1
    if (queue->_readIndex == queue->_maxLength)
    3f96:	3c79 0000 f1b0 	movea.w f1b0 <keyboard+0x8c>,a6
    if (queue->length == queue->_maxLength)
    3f9c:	3a39 0002 97d4 	move.w 297d4 <events+0x6>,d5
    3fa2:	3839 0002 97d2 	move.w 297d2 <events+0x4>,d4
    3fa8:	3439 0002 97d8 	move.w 297d8 <events+0xa>,d2
    queue->contents[queue->_writeIndex] = element;
    3fae:	45f9 0002 97ce 	lea 297ce <events>,a2
    3fb4:	47f9 0000 6a34 	lea 6a34 <CSWTCH.5>,a3
    if (rawKeyCode == KEY_RESET_WARNING ||
    3fba:	0c00 0078      	cmpi.b #120,d0
    3fbe:	6700 009c      	beq.w 405c <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0x132>
    3fc2:	1200           	move.b d0,d1
    3fc4:	5e01           	addq.b #7,d1
    3fc6:	0c01 0001      	cmpi.b #1,d1
    3fca:	6300 0090      	bls.w 405c <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0x132>
        rawKeyCode == KEY_OUTPUT_BUFFER_OVERFLOW ||
    3fce:	5701           	subq.b #3,d1
    3fd0:	0c01 0002      	cmpi.b #2,d1
    3fd4:	6300 0086      	bls.w 405c <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0x132>
    UWORD subType = (rawKeyCode & 0x80) ? EVENT_SUBTYPE_KEYBOARD_KEY_RELEASE
    3fd8:	4a00           	tst.b d0
    3fda:	6d00 00fa      	blt.w 40d6 <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0x1ac>
    3fde:	7e01           	moveq #1,d7
    UBYTE keyCode = rawKeyCode & 0x7f;
    3fe0:	1200           	move.b d0,d1
    3fe2:	0201 007f      	andi.b #127,d1
    if ((keyCode & 0x70) == 0x60) {
    3fe6:	0200 0070      	andi.b #112,d0
    3fea:	0c00 0060      	cmpi.b #96,d0
    3fee:	6700 00fa      	beq.w 40ea <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0x1c0>
    if (queue->length == 0)
    3ff2:	4a43           	tst.w d3
    3ff4:	6700 012c      	beq.w 4122 <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0x1f8>
    void * element = queue->contents[queue->_readIndex];
    3ff8:	7000           	moveq #0,d0
    3ffa:	3009           	move.w a1,d0
    3ffc:	d080           	add.l d0,d0
    3ffe:	d080           	add.l d0,d0
    4000:	2879 0000 f1aa 	movea.l f1aa <keyboard+0x86>,a4
    4006:	2874 0800      	movea.l (0,a4,d0.l),a4
    queue->length--;
    400a:	5343           	subq.w #1,d3
    queue->_readIndex++;
    400c:	5249           	addq.w #1,a1
    if (queue->_readIndex == queue->_maxLength)
    400e:	300e           	move.w a6,d0
    4010:	b049           	cmp.w a1,d0
    4012:	6700 013c      	beq.w 4150 <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0x226>
    keyboardEvent->subType = subType;
    4016:	3947 0008      	move.w d7,8(a4)
    keyboardEvent->keyCode = keyCode;
    401a:	1941 000a      	move.b d1,10(a4)
    keyboardEvent->modifiers = keyboard.modifiers;
    401e:	3039 0000 f1b6 	move.w f1b6 <keyboard+0x92>,d0
    4024:	3940 0006      	move.w d0,6(a4)
    custom->intena = INTF_INTEN;
    4028:	2a79 0000 8aa8 	movea.l 8aa8 <custom>,a5
    402e:	3b7c 4000 009a 	move.w #16384,154(a5)
    if (queue->length == queue->_maxLength)
    4034:	b845           	cmp.w d5,d4
    4036:	671e           	beq.s 4056 <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0x12c>
    queue->contents[queue->_writeIndex] = element;
    4038:	7000           	moveq #0,d0
    403a:	3002           	move.w d2,d0
    403c:	d080           	add.l d0,d0
    403e:	d080           	add.l d0,d0
    4040:	2a52           	movea.l (a2),a5
    4042:	2b8c 0800      	move.l a4,(0,a5,d0.l)
    queue->length++;
    4046:	5244           	addq.w #1,d4
    queue->_writeIndex++;
    4048:	5242           	addq.w #1,d2
    404a:	2a79 0000 8aa8 	movea.l 8aa8 <custom>,a5
    if (queue->_writeIndex == queue->_maxLength)
    4050:	b445           	cmp.w d5,d2
    4052:	6700 0102      	beq.w 4156 <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0x22c>
    custom->intena = INTF_SETCLR | INTF_INTEN;
    4056:	3b7c c000 009a 	move.w #-16384,154(a5)
    if (keyboard.rawKeyCodeBuffer.length == 0)
    405c:	3039 0000 f1a4 	move.w f1a4 <keyboard+0x80>,d0
    4062:	6740           	beq.s 40a4 <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0x17a>
    UBYTE rawKeyCode = keyboard.rawKeyCodeBuffer.contents[keyboard.rawKeyCodeBuffer._readIndex];
    4064:	3039 0000 f1a6 	move.w f1a6 <keyboard+0x82>,d0
    406a:	0280 0000 ffff 	andi.l #65535,d0
    4070:	1030 0800      	move.b (0,a0,d0.l),d0
    keyboard.rawKeyCodeBuffer.length--;
    4074:	3239 0000 f1a4 	move.w f1a4 <keyboard+0x80>,d1
    407a:	5341           	subq.w #1,d1
    407c:	33c1 0000 f1a4 	move.w d1,f1a4 <keyboard+0x80>
    keyboard.rawKeyCodeBuffer._readIndex++;
    4082:	3239 0000 f1a6 	move.w f1a6 <keyboard+0x82>,d1
    4088:	5241           	addq.w #1,d1
    408a:	33c1 0000 f1a6 	move.w d1,f1a6 <keyboard+0x82>
    if (keyboard.rawKeyCodeBuffer._readIndex == RAW_KEY_CODE_BUFFER_MAX_LENGTH)
    4090:	3239 0000 f1a6 	move.w f1a6 <keyboard+0x82>,d1
    4096:	0c41 0080      	cmpi.w #128,d1
    409a:	6728           	beq.s 40c4 <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0x19a>
    for (UBYTE rawKeyCode = Keyboard_Interrupt_FetchRawKeyCodeFromBuffer();
    409c:	0c00 ffff      	cmpi.b #-1,d0
    40a0:	6600 ff18      	bne.w 3fba <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0x90>
    40a4:	33c3 0000 f1ae 	move.w d3,f1ae <keyboard+0x8a>
    40aa:	33c9 0000 f1b2 	move.w a1,f1b2 <keyboard+0x8e>
    40b0:	33c4 0002 97d2 	move.w d4,297d2 <events+0x4>
    40b6:	33c2 0002 97d8 	move.w d2,297d8 <events+0xa>
}
    40bc:	7001           	moveq #1,d0
    40be:	4cdf 7cfc      	movem.l (sp)+,d2-d7/a2-a6
    40c2:	4e75           	rts
        keyboard.rawKeyCodeBuffer._readIndex = 0;
    40c4:	33fc 0000 0000 	move.w #0,f1a6 <keyboard+0x82>
    40ca:	f1a6 
    for (UBYTE rawKeyCode = Keyboard_Interrupt_FetchRawKeyCodeFromBuffer();
    40cc:	0c00 ffff      	cmpi.b #-1,d0
    40d0:	6600 fee8      	bne.w 3fba <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0x90>
    40d4:	60ce           	bra.s 40a4 <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0x17a>
    UWORD subType = (rawKeyCode & 0x80) ? EVENT_SUBTYPE_KEYBOARD_KEY_RELEASE
    40d6:	7e02           	moveq #2,d7
    UBYTE keyCode = rawKeyCode & 0x7f;
    40d8:	1200           	move.b d0,d1
    40da:	0201 007f      	andi.b #127,d1
    if ((keyCode & 0x70) == 0x60) {
    40de:	0200 0070      	andi.b #112,d0
    40e2:	0c00 0060      	cmpi.b #96,d0
    40e6:	6600 ff0a      	bne.w 3ff2 <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0xc8>
        switch (keyCode) {
    40ea:	1001           	move.b d1,d0
    40ec:	0600 ffa0      	addi.b #-96,d0
    40f0:	0c00 0007      	cmpi.b #7,d0
    40f4:	626c           	bhi.s 4162 <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0x238>
    40f6:	0280 0000 00ff 	andi.l #255,d0
    40fc:	d080           	add.l d0,d0
    40fe:	3a73 0800      	movea.w (0,a3,d0.l),a5
            keyboard.modifiers |= modifier;
    4102:	3879 0000 f1b6 	movea.w f1b6 <keyboard+0x92>,a4
    4108:	300d           	move.w a5,d0
        if (subType == EVENT_SUBTYPE_KEYBOARD_KEY_PRESS)
    410a:	0c47 0001      	cmpi.w #1,d7
    410e:	6756           	beq.s 4166 <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0x23c>
            keyboard.modifiers &= ~modifier;
    4110:	4640           	not.w d0
    4112:	3c0c           	move.w a4,d6
    4114:	c046           	and.w d6,d0
    4116:	33c0 0000 f1b6 	move.w d0,f1b6 <keyboard+0x92>
    if (queue->length == 0)
    411c:	4a43           	tst.w d3
    411e:	6600 fed8      	bne.w 3ff8 <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0xce>
    4122:	33fc 0000 0000 	move.w #0,f1ae <keyboard+0x8a>
    4128:	f1ae 
    412a:	33c9 0000 f1b2 	move.w a1,f1b2 <keyboard+0x8e>
    4130:	33c4 0002 97d2 	move.w d4,297d2 <events+0x4>
    4136:	33c2 0002 97d8 	move.w d2,297d8 <events+0xa>
    keyboardEvent->subType = subType;
    413c:	31fc 0000 0008 	move.w #0,8 <_start+0x8>
    4142:	4e47           	trap #7
        keyboard.rawKeyCodeBuffer._readIndex = 0;
    4144:	33fc 0000 0000 	move.w #0,f1a6 <keyboard+0x82>
    414a:	f1a6 
    414c:	6000 fe34      	bra.w 3f82 <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0x58>
        queue->_readIndex = 0;
    4150:	93c9           	suba.l a1,a1
    4152:	6000 fec2      	bra.w 4016 <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0xec>
        queue->_writeIndex = 0;
    4156:	4242           	clr.w d2
    custom->intena = INTF_SETCLR | INTF_INTEN;
    4158:	3b7c c000 009a 	move.w #-16384,154(a5)
    if (FALSE) {
    415e:	6000 fefc      	bra.w 405c <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0x132>
    if ((keyCode & 0x70) == 0x60) {
    4162:	9bcd           	suba.l a5,a5
    4164:	609c           	bra.s 4102 <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0x1d8>
            keyboard.modifiers |= modifier;
    4166:	3c0c           	move.w a4,d6
    4168:	8046           	or.w d6,d0
    416a:	33c0 0000 f1b6 	move.w d0,f1b6 <keyboard+0x92>
    4170:	6000 fe80      	bra.w 3ff2 <Keyboard_Interrupt_ProcessRawKeyCodeBuffer+0xc8>

The compiler seems to be doing a lot, but I'm going to spend a little bit of time trying to understand it before I start turning off optimisations.

[deimos]

So, here's what I currently think: The traps are part of the way gcc makes interrupt capable functions. They do stuff and they work (the code looks like they must be being executed for a bit before they crash, right?). But somewhere, sooner or later (or straight away when Russ runs it) that trap vector gets broken and points to the wrong place. Then, when an interrupt is called, it triggers that trap, and everything falls apart.

So, I should be looking for where the trap gets overwritten.

Does that sound plausible?

[deimos]

The traps only appear if I have link time optimisation (-lto) enabled.

[meynaf]

Originally Posted by deimos

So, here's what I currently think: The traps are part of the way gcc makes interrupt capable functions. They do stuff and they work (the code looks like they must be being executed for a bit before they crash, right?). But somewhere, sooner or later (or straight away when Russ runs it) that trap vector gets broken and points to the wrong place. Then, when an interrupt is called, it triggers that trap, and everything falls apart.

So, I should be looking for where the trap gets overwritten.

Does that sound plausible?

No it doesn't sound plausible. Crashing with a guru indicating trap #7 means the vector wasn't touched at all and still points to normal rom. In addition, the code doesn't look like if it was trying to do anything interrupt related (or anything right at all) - the trap isn't the only instruction here that doesn't look right. And of course, the traps would still be there without link time optimisation if it was intentional...

Originally Posted by deimos

The traps only appear if I have link time optimisation (-lto) enabled.

Now you know the culprit.

[deimos]

Originally Posted by meynaf

Now you know the culprit.

Yes, but it's all very frustrating. I don't know enough about the lto stuff to report a meaningful bug, and I'm really bothered by not knowing whether it was trying but failing to do something useful or whether it's just completely broken. And my code is still crashy, just in a different way now.

[sparhawk]

Originally Posted by deimos

The traps only appear if I have link time optimisation (-lto) enabled.

This might be an indication that your code is somewhere wrong. Which compiler are you using? gcc? The optimizer ("lto" is one of them) is free to insert even "wrong" code when it can "proof" that there is a problem with the code.
I once had a jmp to 0 generated because of that, thinking it was a compiler bug, but it was not. It was the compilers way to tell me that I had some bug in the code that leads to invalid code.


If you use gcc, you should switch on "-save-temps -O1 -g", because having no optimization at all makes the code much harder to read. O1 is just enough to make the code better understandable without hardcore optimizations which makes it much harder to follow. Does it work without "lto"? While developing it might be better to switch this off for now.

[deimos]

Originally Posted by sparhawk

This might be an indication that your code is somewhere wrong. Which compiler are you using? gcc? The optimizer ("lto" is one of them) is free to insert even "wrong" code when it can "proof" that there is a problem with the code.
I once had a jmp to 0 generated because of that, thinking it was a compiler bug, but it was not. It was the compilers way to tell me that I had some bug in the code that leads to invalid code.


If you use gcc, you should switch on "-save-temps -O1 -g", because having no optimization at all makes the code much harder to read. O1 is just enough to make the code better understandable without hardcore optimizations which makes it much harder to follow. Does it work without "lto"? While developing it might be better to switch this off for now.

Yes, gcc. My code is very crashy crashy at the moment, so I wouldn't be surprised if fixing my bugs also fixes the optimised code, particularly as the bugs seem to be in the same place as the traps. I'll try the flags you've suggested, but at the moment I need at least -O2, something to do with the inline keyword, that I haven't figured out the correct flags for.

[ross]

Originally Posted by sparhawk

I once had a jmp to 0 generated because of that, thinking it was a compiler bug, but it was not. It was the compilers way to tell me that I had some bug in the code that leads to invalid code.

So this is the compiler way to help you? Add bugs to your bugs?
Fantastic!

[hooverphonique]

Originally Posted by ross

So this is the compiler way to help you? Add bugs to your bugs?
Fantastic!

I suppose undefined behavior getting turned into a hard crash is preferable over actual undefined behavior!?

[sparhawk]

Originally Posted by hooverphonique

I suppose undefined behavior getting turned into a hard crash is preferable over actual undefined behavior!?

Definitely. I prefer predictable crashes, because they are easy to fix.



@deimos

I forgot one switch. You should also add '-fverbose-asm' because this way it inserts information in the asm so you can more easily map the code to your source.

[sparhawk]

Originally Posted by ross

So this is the compiler way to help you? Add bugs to your bugs?
Fantastic!

Not sure, but I could assume that the reasoning is like this:


The compiler is free to remove, reorder or change code as long as the observable behavior is the same. So when the optimizer detects that the observable behavior will be a crash, it can of course insert code, that does exactly that.


Don't take it to seriously, though...

[meynaf]

When compiler, linker, optimizer, or whatever, detects that there will be a crash, the smallest of things should be to emit a warning about it...

[a/b]

http://gcc.1065356.n8.nabble.com/m68...td1518765.html

[deimos]

Originally Posted by a/b

http://gcc.1065356.n8.nabble.com/m68...td1518765.html

"if the compiler is inserting traps, the program is horribly buggy at those points"

It's like he knows me.

[sparhawk]

https://stackoverflow.com/questions/...a-call-to-null

The conclusion is similar to the above link, as I said before. The sample here is from an Intel binary, but the problem is the same. Undefined behavior triggers gcc to insert such instructions. No warning emitted...

So maybe you can post the C/C++ code for better investigation.

[deimos]

Originally Posted by sparhawk

https://stackoverflow.com/questions/...a-call-to-null

The conclusion is similar to the above link, as I said before. The sample here is from an Intel binary, but the problem is the same. Undefined behavior triggers gcc to insert such instructions. No warning emitted...

So maybe you can post the C/C++ code for better investigation.

The complete source is attached back in post #7. Because of all the inlining the compiler does it's hard to just post snippets.

The problem is around my keyboard handling code (keyboard.c and game_interrupt_handler.c), which I had believed to be working when I wrote it a few months ago, but I now know fails when you press two keys at exactly the same time. This code has cruft - my whole code base does, so I apologise in advance. I don't remember my motivation for a lot of it either.

[sparhawk]

One thing I already notice is, this line:

    if (keyboard.rawKeyCodeBuffer.length == RAW_KEY_CODE_BUFFER_MAX_LENGTH)
        return;

I would change it to ">=" instead of "==". Not sure if this is called from an interrupt or such, so it can have concurrent access. If this is the case then it might overflow the length and your guard no longer works. Since you mentioned that pressing multiple keys, this could be one issue. The same problem would apply where you check "== 0" as well.

The same would apply to other cases where you are checking the length. I don't see any safeguards there, so you might need some locking mechanism if this can be called concurrently.

But I don't think that this is your problem, because gcc wouldn't know about this.

[deimos]

Originally Posted by sparhawk

But I don't think that this is your problem, because gcc wouldn't know about this.

Plus, if we've gone over the length we're already screwed.

I do probably need to think about my concurrency though. I originally had an over complex locking system, which I threw out for just disabling interrupts, but I need to check what I'm doing. But, I don't think that's the problem, as I made that change after I discovered my issues.

[phx]

When you know the trap is in Keyboard_Interrupt_ProcessRawKeyCodeBuffer(), then the frist thing I would do is to compile this source with -S and look at the assembler output the compiler generates. Although I wouldn't expect it, after reading the link given by a/b, but it might also be possible that the assembler is generating bad code for an instruction.

Otherwise I agree with Meynaf that I wouldn't accept a compiler which intentionally inserts illegal instructions into my code without giving any note. So turn this "feature" off, if you can (the link suggests you can).

[deimos]

Originally Posted by phx

When you know the trap is in Keyboard_Interrupt_ProcessRawKeyCodeBuffer(), then the frist thing I would do is to compile this source with -S and look at the assembler output the compiler generates. Although I wouldn't expect it, after reading the link given by a/b, but it might also be possible that the assembler is generating bad code for an instruction.

Otherwise I agree with Meynaf that I wouldn't accept a compiler which intentionally inserts illegal instructions into my code without giving any note. So turn this "feature" off, if you can (the link suggests you can).

Surely the first thing you'd do is look at your C code hoping to spot a simple coding mistake?

The code is still buggy when compiled without the link time optimisation that introduces this feature, just in a crash later instead of now kind of way (i.e. the traps aren't inserted and the code is with undefined behaviour is left untouched), although it appears solid (to me) unless you hit two keys at exactly the same time.

The minimum optimisation level I've been able to compile with is -O2, due to the inline keyword and the way gcc has implemented the different standards. If I can figure out how, I'll compile with -O1 instead.

I've attached a .s file for the complete program (with everything else that's happening I think this is the best route, plus it's generated as part of the build, disassembled from the elf) and the executable, compiled with -O2 and without -lto.