z88dk forums

Mochilote · 2012-02-05 15:28:30

Doing some tests I found these strange differences between multiple versions of the compiler, the same code shows different results in execution.

I have tested with versions v1.8 (official), v1.9 (official), Nightly build v20111101.

The code is basically a infinite loop that measures time (and loops counter) and shows a text every second (measure time don't include printf time). For measuring time i have used a Amstrad firmware function (KL TIME PLEASE) that returns the time that has elapsed since the computer was switched on or reset (in 1/300ths of a second). From my experience I think that this counter does not increase with interrupts disabled.

Results:
z88dk v1.8: Every second the printf shows about 2600 loops (works as expected)
z88dk v1.9: Every 7 seconds shows about 19000 loops
z88dk v20111101: Every 3 seconds shows about 8400 loops

All the programs runs at 'same velocity' (2600 * 7 = 18000 loops, 2600 * 3 = 7800 loops), but only in v1.8 Amstrad firmware function (KL TIME PLEASE) works as expected, the others 'must disable interrupts longer'.

The code:

Code:

#include <stdio.h>

////////////////////////////////////////////////////////////////////////
unsigned char char1,char2,char3,char4;

unsigned int GetTime()
{
    unsigned int nTime = 0;
    
    #asm
        CALL $BD0D //KL TIME PLEASE
        PUSH HL
        /*
        LD HL, _char1
        LD (HL), D
        LD HL, _char2
        LD (HL), E
        */
        POP DE
        LD HL, _char3
        LD (HL), D
        LD HL, _char4
        LD (HL), E
    #endasm
    
    nTime = (char3 << 8) + char4;

    return nTime;
}
////////////////////////////////////////////////////////////////////////

main()
{
    unsigned int nFPS = 0;
    unsigned int nTimeLast = 0;
    unsigned int nTimeDiff = 0;

    nTimeLast = GetTime();

    while(1)
    {
        nFPS++;
        nTimeDiff = GetTime() - nTimeLast;
        if(nTimeDiff >= 300)
        {
            printf("Fps %u, time %u\n", nFPS, nTimeDiff);

            nTimeLast = GetTime();
            nFPS = 0;
        }
    }

}

Mochilote · 2012-02-09 23:15:43

Mochilote wrote:
Results:
z88dk v1.8: Every second the printf shows about 2600 loops (works as expected)
z88dk v1.9: Every 7 seconds shows about 19000 loops
z88dk v20111101: Every 3 seconds shows about 8400 loops

Hi again, i finally managed to compile it on SDCC 3.1.0 and it works perfectly, every second the printf shows about 4860 loops, about 40% faster code than generated by z88dk...

stefano · 2012-02-10 13:57:54

Sorry I still couldn't experiment myself.
Are you sure the timer is active 'all the time' ?
Couldn't it just depend on the way the interrputs are managed ? I vaguely remember some aggressive patch having to do with the interrupts or so.. but if you actually see the code running slower, then you must be right.

Mochilote · 2012-02-10 14:35:41

stefano wrote:
Are you sure the timer is active 'all the time' ? Couldn't it just depend on the way the interrputs are managed ?

As I said in the first message "I think that this counter does not increase with interrupts disabled", so I guess that interrupts are disabled several times more than 3ms and therefore does not increase the time counter.

But this works perfectly in z88dk v1.8 and SDCC 3.1.0, on z88dk v1.9 and v20111101 costs them 7 and 3 seconds respectively (measured visually for me in the emulator) to increase the timer on what is supposed to be one second. It is also interesting that in each version of z88dk, the same code behaves differently.

Furthermore, in cases in which it works well, it is interesting to note the difference of loops that achieves SDCC against z88dk .

Cheers.

Mochilote · 2012-02-11 12:44:42

My suspicions are confirmed:

The following code, compiled in the three versions of z88dk give us the same result:

Code:

#include <stdio.h>

////////////////////////////////////////////////////////////////////////
unsigned char char1,char2,char3,char4;

unsigned int GetTime()
{
    unsigned int nTime = 0;
    
    #asm
        CALL $BD0D //KL TIME PLEASE
        PUSH HL
        /*
        LD HL, _char1
        LD (HL), D
        LD HL, _char2
        LD (HL), E
        */
        POP DE
        LD HL, _char3
        LD (HL), D
        LD HL, _char4
        LD (HL), E
    #endasm
    
    nTime = (char3 << 8) + char4;

    return nTime;
}
////////////////////////////////////////////////////////////////////////

main()
{
    unsigned int nCounter = 0;
    unsigned int nLoops = 0;

    printf("time %u\n", GetTime());

    for(nCounter = 0; nCounter < 65535; nCounter++)
        nLoops++;

    printf("time %u, loops %u\n", GetTime(), nLoops);

    while (getk() != 13) {};
}

Result:

Between one printf and the other, program spends about 4 seconds, so the second time value should be at least of 1200.

If you compile the same code in sdcc obtain the following result:

Between one printf and the other, program spends less than a second, impressive difference.

Now, if I disable interrupts for just before the 'for' and enable them again after the 'for', we obtain the following result (in SDCC, of course):

So the question is why in this code z88dk are disabling interrupts all the time?

Cheers.

stefano · 2012-02-14 14:25:23

I can't recall exactly but it happened in May 2008, with the creation of the CP/M compatible lib and the firmware niterposer. I suppose it had to do with something discovered on the 6128.. I'll re-enable the interrupts making them disabled on option only.

http://z88dk.cvs.sourceforge.net/viewvc … p;view=log

stefano · 2012-02-17 13:40:17

CRT0 file updated. This new version disables the interrupts only if the '-startup=2' parameter is added in the compiler command line.

Mochilote · 2012-02-18 13:18:07

I have used snapshot 20120208 to compile it, but i get unstable results:

-The program freezes when calling GetTime
-If I delete calls to GetTime, however, the display is corrupted...

stefano · 2012-02-20 07:01:57

Could you please try one more thing ?
Remove the semicolon in line 68 of cpc_crt0.asm (di instruction), it will disable the soft interrupts but the hard ones will be kept, as it was in origin.
Honestly I'd still expect some instability, if so we'll just need to understand which registers the Amstrad(s) need to keep untouched and protect them.

stefano · 2012-02-20 07:57:31

Forget my last post
I just realized some BIOS calls just need to have the interrupts disabled to run correctly, so the fix should be applied onto the libs rather than on the startup code.

z88dk forums

#1 2012-02-05 15:28:30

Unexpected and different results between compiler versions...

Code:

#2 2012-02-09 23:15:43

Re: Unexpected and different results between compiler versions...

Mochilote wrote:

#3 2012-02-10 13:57:54

Re: Unexpected and different results between compiler versions...

#4 2012-02-10 14:35:41

Re: Unexpected and different results between compiler versions...

stefano wrote:

#5 2012-02-11 12:44:42

Re: Unexpected and different results between compiler versions...

Code:

#6 2012-02-14 14:25:23

Re: Unexpected and different results between compiler versions...

#7 2012-02-17 13:40:17

Re: Unexpected and different results between compiler versions...

#8 2012-02-18 13:18:07

Re: Unexpected and different results between compiler versions...

#9 2012-02-20 07:01:57

Re: Unexpected and different results between compiler versions...

#10 2012-02-20 07:57:31

Re: Unexpected and different results between compiler versions...

Board footer