Unexpected and different results between compiler versions...

Amstrad CPC and NC systems
Post Reply
Mochilote
Member
Posts: 42
Joined: Thu Jul 19, 2007 10:54 am

Unexpected and different results between compiler versions...

Post by Mochilote »

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: Select all

#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
Member
Posts: 42
Joined: Thu Jul 19, 2007 10:54 am

Post by Mochilote »

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
Well known member
Posts: 1534
Joined: Mon Jul 16, 2007 7:39 pm

Post by stefano »

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
Member
Posts: 42
Joined: Thu Jul 19, 2007 10:54 am

Post by Mochilote »

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 :D.

Cheers.
Mochilote
Member
Posts: 42
Joined: Thu Jul 19, 2007 10:54 am

Post by Mochilote »

My suspicions are confirmed:

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

Code: Select all

#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:
Image

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:
Image

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):
Image

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

Cheers.
stefano
Well known member
Posts: 1534
Joined: Mon Jul 16, 2007 7:39 pm

Post by stefano »

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 ... 8&view=log
stefano
Well known member
Posts: 1534
Joined: Mon Jul 16, 2007 7:39 pm

Post by stefano »

CRT0 file updated. This new version disables the interrupts only if the '-startup=2' parameter is added in the compiler command line.
Mochilote
Member
Posts: 42
Joined: Thu Jul 19, 2007 10:54 am

Post by Mochilote »

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
Well known member
Posts: 1534
Joined: Mon Jul 16, 2007 7:39 pm

Post by stefano »

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
Well known member
Posts: 1534
Joined: Mon Jul 16, 2007 7:39 pm

Post by stefano »

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.
violadavis
New member
Posts: 4
Joined: Wed Oct 09, 2013 5:10 am

Post by violadavis »

Yeah, I have seen this before. The same code shows different results in execution if we use different compiler versions. I don't know which result to trust. This is really a serious problem associated with the same. Actually the compiler version should not affect the results!



_________________________________
www.omnitechsupport.com
maschinist
New member
Posts: 3
Joined: Sun Jan 27, 2013 8:58 pm

Post by maschinist »

At first, the observations and statements are right.

-->But it's not a problem with the compiler at all, it just rocks.

It is an issue with the stdio and the startup code.
But it could easily be fixed.

Image

Remember:
A system friendly, stable program on the cpc must never touch the shadow registers
(reserved by the OS) nor should it disable interrupts, since all keyboard processing, color blinking and sound depends on it.

Therefore, a very simple cpc_crt0.asm without DI, without EXX is just right for the cpc.

To make your code above run, at least fput_cons() and printf() must be a improved
to not use Z80 shadow registers, I did that, see below.

Well, its worth to be discussed with stefano and dom and the others if we can provide stdio to support the CPC this (cpc friendly) way.

I attached the dsk, makefile and src of your example
[http://rst.in-chemnitz.de/cpc/z88dkdemos/demo2/]right here...[/url]


I want to say, Z88DK is really brilliant for the CPC. Thanky you guys. Great Job.
maschinist
New member
Posts: 3
Joined: Sun Jan 27, 2013 8:58 pm

Post by maschinist »

I forgot to mention, this post relates to the actual release

z88dk-1.10.1
alvin
Well known member
Posts: 1872
Joined: Mon Jul 16, 2007 7:39 pm

Post by alvin »

maschinist wrote:Remember:
A system friendly, stable program on the cpc must never touch the shadow registers
(reserved by the OS) nor should it disable interrupts, since all keyboard processing, color blinking and sound depends on it.
In the existing (ie 1.10) libraries the exx set is used in numerous places. For example, long arithmetic and multiplication and division code even for integers is substantially sped up by using the exx set. I think most of the rest of the libraries are not using it, except perhaps the graphics library.

The new library is using the exx set extensively. stdio is using one side of the registers to generate messages (the printf / scanf side, etc) and the other side is used as a state machine by the device driver to qualify stream input. Again all math is using it.

For the ROM interrupts do we also need to save the exx set? If we have to maybe we can instead provide an interrupt shell that saves registers and jumps to the ROM entry. There will also be an option to run ROMless so that interrupts can be disabled or used for other purposes.

When making other firmware calls (eg DOS calls) is it possible to set the EXX registers to a known set of values before making the call?
maschinist
New member
Posts: 3
Joined: Sun Jan 27, 2013 8:58 pm

Post by maschinist »

Yes. To use both, the ROM and the LIB and without crashing the cpc could work this way:

Code: Select all

main:
disable interrupts
save rom exx registers
..
use lib functions
..
save lib exx registers
restore rom exx registers
enable interrupts
-->call CPC ROM function
disable interrupts
save rom exx registers
restore lib exx registers
..
use lib functions
..

restore rom exx registers
enable interrupts
return to basic ($c9)
So, either all ROM calls or all LIB calls must be wrapped with exx register and interrupt management.
When in standard ROM mode, interrupts should be on.
When in LIB mode, interrupts must be off. As a consequence key strokes get lost, the software clock freezes, music and sound freeze.

As another workaround of this, the cpc interrupt handler could be wrapped to restore
the rom content of the exx registers on entry.

Its tricky and probably faulty, but its probably worth a try to get both, ROM and LIB covered this way.

Alternatively, at the moment I am very happy with the z88dk in CPC-ROM
friendly mode (not using exx at all) since I managed to use all the integer and floating point
math and trigonometric functions, the graphics and ROM functions, some stdio functions and malloc.
It does really nicely interoperate with the system and with BASIC etc.
Im providing my example programs here.

Isn't there a way to provide printf, scanf, fopen, fgets... for cpc users not using the shadow registers?
I'd really like to support that. :-)
alvin
Well known member
Posts: 1872
Joined: Mon Jul 16, 2007 7:39 pm

Post by alvin »

maschinist wrote:As another workaround of this, the cpc interrupt handler could be wrapped to restore
the rom content of the exx registers on entry.

Its tricky and probably faulty, but its probably worth a try to get both, ROM and LIB covered this way.
I'm pretty confident we can do that.

We can just set aside some bytes to hold the ROM's current exx set.

On interrupt, we save the exx set and load up the ROM's exx set before jumping to the ROM isr. I don't know if that means we're supplying an im2 handler or if the cpc allows alternate code to be run on interrupt.

The library will only call the firmware through one or a few entry points and it's easy to restore the ROM exx set just before the firmware call. There's a race condition if an int occurs while the exx set is being loaded so I guess we'll have to di around that briefly.
Alternatively, at the moment I am very happy with the z88dk in CPC-ROM
friendly mode (not using exx at all) since I managed to use all the integer and floating point
math and trigonometric functions, the graphics and ROM functions, some stdio functions and malloc.
It does really nicely interoperate with the system and with BASIC etc.
Im providing my example programs here.
Long integer math will probably not work and that includes simple addition and subtraction. Long math is sped up considerably by using the exx set and there is no alternative code in the z88dk codebase for that currently.

The floating point is working because stef added the cpc rom fp routines as the default option for float library on the cpc target. The native z88dk float library is called 'genmath' and it also uses the exx set so it probably won't work too. You can select genmath on the compile line with -lmz (my memory is really bad here -- I hope I got that right!).

But I'm glad there is finally something that works nearly correctly on the cpc. Sometimes it's hard to know what is going wrong when you're not an expert on a particular system :) The changes you've made should be added for the cpc on the 1.10 libraries.
Isn't there a way to provide printf, scanf, fopen, fgets... for cpc users not using the shadow registers?
I'd really like to support that. :-)
Do these things not yet work with 1.10? I don't recall there being use of the exx set in the 1.10 stdio?

The new library is a parallel library that is aiming to be more C11 compliant; you'll be able to select between the current and the new one on the compile line. The new one has been designed from the ground up to use the exx set in order to eliminate the need for high-level buffering (setvbuf sort of thing) and to improve performance. This decision will show up in all the drivers (block, character, terminal) but I don't think it's an issue. I'm pretty sure we can do what is suggested above to make things work without any kind of penalty.
stefano
Well known member
Posts: 1534
Joined: Mon Jul 16, 2007 7:39 pm

Post by stefano »

Back to this topic, I never managed to get a stable way to call the firmware functions in a stable way when interrupts are enabled.

I'd like to try it again, what I have in mind is, as suggested to:

restore rom exx registers
enable interrupts
-->call CPC ROM function
disable interrupts
save rom exx registers


So, here are the questions:
Is it necessary to save the rom exx registers everytime or it is enough to set them as they are at startup ?
Are such registers BC' and AF' only ?
What about SP ? we're just lowering by 6k at the moment, should it be set differently ? What to do while in interrupts ?
Post Reply