printf not printing doubles (solved!)

[Pate]

Hi!

I am having a weird problem in my rpix86 debugging routine.. I can't seem to print double (or float) variables using printf. I can't seem to figure out what i am doing wrong, perhaps you can help?

My printf call is currently like this (I hardcoded the values after I could not figure out what is wrong with my variable access):

printf("%p %02X%02X TOP=%d, sw=%04X, 0=%.6f, 1=%.6f, 2=%.6f, 3=%.6f", csip, *csip, *(csip+1), GP_fpu_top, GP_fpu_sw,
1.0, //GP_fpu_regs[GP_fpu_top&7],
2.0, //GP_fpu_regs[(GP_fpu_top+1)&7],
3.0, //GP_fpu_regs[(GP_fpu_top+2)&7],
4.0); //GP_fpu_regs[(GP_fpu_top+3)&7]);

The output is like this:

0x4281b0c7 DBE3 TOP=0, sw=0000, 0=0.000000, 1=0.000000, 2=0.000000, 3=72745825311706873250527073421153621921560813641299736244219917557672442491530443982743201828743566608632003762904217641062388007831250104821199964247325433820238002167777572874426379873158203069956096.000000

On separate calls to this routine, the first three double values are always zero, the third gets various random-like values.

If I separately print just this:

printf("%f", 1.0);

I get:

0.000000

I tried including <math.h> but that did not help... I have tried all sorts of things but no matter what I try, floating point numbers never print anything sensible.

Any ideas?

Pate

[experix]

printf problems often turn out to be the wrong specifier used with a variable. I can't tell from what you posted because you don't include the declarations.

[PeterO]

Works for me !

Code: Select all

[email protected] ~ $ cat fp.c
#include <stdio.h>

int main(int argc,char **argv)
{
    printf("%f\n",1.0);
    return(0);
}

[email protected] ~ $ gcc -Wall -o fp  fp.c
[email protected] ~ $ ./fp
1.000000
[email protected] ~ $ 

[plugwash]

How are you compiling this code?

[Pate]

Thanks for the replies!

@experix: This is the whole function:

Code: Select all

extern char GP_fpu_top;
extern short GP_fpu_sw;
extern double GP_fpu_regs[];

void log_fpu_c(unsigned char *csip)
{
    printf("%p %02X%02X TOP=%d, sw=%04X, 0=%.6f, 1=%.6f, 2=%.6f, 3=%.6f", csip, *csip, *(csip+1), GP_fpu_top, GP_fpu_sw,
        1.0, //GP_fpu_regs[GP_fpu_top&7],
        2.0, //GP_fpu_regs[(GP_fpu_top+1)&7],
        3.0, //GP_fpu_regs[(GP_fpu_top+2)&7],
        4.0); //GP_fpu_regs[(GP_fpu_top+3)&7]);
}

@PeterO: Yes, I know it should work, which is why I am at my wit's end as to why it doesn't.

@plugwash: Sorry I'm not at my Raspberry Pi at the moment so I can not give the exact command line, but looking at my Makefile it is something like this:

gcc -g -Wall -O2 -mthumb -mthumb-interwork -I./include -I./build -I/opt/vc/include -I/opt/vc/include/interface/vcos/pthreads ./source/rpix86.c -o ./build/rpix86.o

I used objdump and disassembly for the rpix86.o object module, and on quick look it looked like the compiler put the "printf("%f", 1.0);" format string into r0 register and the 1.0 double value into r2,r3 pair, not into r1,r2 register pair as I would have expected. When I get back to my Raspberry Pi I plan to experiment making the same printf call from an ASM module using r0, r1 and r2 registers, to see if that produces the correct result.

Pate

[plugwash]

Are you building natively or cross? what OS are you using? are you using the compiler toolchain that came with the OS or something else.

[PeterO]

Thanks for the replies!
@PeterO: Yes, I know it should work, which is why I am at my wit's end as to why it doesn't.

The point is that it does work in the simple case that you say it doesn't work in, that means there is something that you are not telling us about that is stopping it working in your particular case. For example, why are you using -mthumb switches in your gcc command lines ?

PeterO

[Paeryn]

I used objdump and disassembly for the rpix86.o object module, and on quick look it looked like the compiler put the "printf("%f", 1.0);" format string into r0 register and the 1.0 double value into r2,r3 pair, not into r1,r2 register pair as I would have expected. When I get back to my Raspberry Pi I plan to experiment making the same printf call from an ASM module using r0, r1 and r2 registers, to see if that produces the correct result.

Doubles on the stack are expected to be 8-byte aligned. Since the first four words are passed in registers rather than on the stack this means doubles have to be passed either in R0-R1 or R2-R3, as a variadic function (printf in this case) is allowed to just push R0-R3 onto the stack and access all items from the stack.

[Paeryn]

In the output you gave with the result

Code: Select all

0x4281b0c7 DBE3 TOP=0, sw=0000, 0=0.000000, 1=0.000000, 2=0.000000, 3=72745825311706873250527073421153621921560813641299736244219917557672442491530443982743201828743566608632003762904217641062388007831250104821199964247325433820238002167777572874426379873158203069956096.000000

That huge number read as hex rather than a double reads 0x0000104066696E69 (or 4 bytes - 0, 0, 16 and 64 followed by the text fini which looks like the start of a string). Is it from when you were printing the GP_fpu_regs data or when hardcoding the values? It looks like there's possibly some data/stack corruption going on.

[Pate]

@plugwash: This is the actual compile command line (I don't know why I had the -mthumb switches in my old Makefile I posted above):

Code: Select all

gcc -MMD -MP -MF /home/pi/rpix86/build/rpix86.d -g -Wall -O2  -I/home/pi/rpix86/include  -I/home/pi/rpix86/build -I/opt/vc/include -I/opt/vc/include/interface/vcos/pthreads -DRPi -c /home/pi/rpix86/source/rpix86.c -o rpix86.o

I am building natively, OS is: Linux raspberrypi 3.2.27+ #250 PREEMPT Thu Oct 18 19:03:02 BST 2012 armv6l GNU/Linux and I am using the default OS compile toolchain.

@PeterO: Yes, you are probably right that I have not mentioned something relevant to my scenario, but the problem is that I don't know what might be the relevant parts. Perhaps the fact that I am calling this C log_fpu_c() routine from an ASM routine? I am calling various other C routines from ASM without problems, so that should not be relevant.

@Paeryn: Thanks for the detailed analysis! That example is from the hardcoded values. I am trying to log the FPU registers after a "finit" FPU operation, so it does indeed look like something is wrong in the stack. I'll focus on that next, thanks!

I'll keep you posted on what I find out, thanks again for all your help!

Pate

[Pate]

This is the objdump result of the log_fpu_c() routine (when giving the literal parameters 1.0, 2.0, 3.0 and 4.0). I added some of my own comments in parentheses. I don't see anything wrong in this call, the doubles are pushed at sp+8, sp+16 etc:

Code: Select all

000035b8 <log_fpu_c>:
    35b8:	e92d4030 	push	{r4, r5, lr}
    35bc:	e1a01000 	mov	r1, r0    ; (r1 = csip)
    35c0:	e5d02000 	ldrb	r2, [r0]    ; (r2 = *csip)
    35c4:	e5d03001 	ldrb	r3, [r0, #1]    ; (r3 = *(csip+1))
    35c8:	e59f0054 	ldr	r0, [pc, #84]	; 3624 <log_fpu_c+0x6c> (r0 = GP_fpu_top address)
    35cc:	e59f5054 	ldr	r5, [pc, #84]	; 3628 <log_fpu_c+0x70> (1.0 high word)
    35d0:	e24dd02c 	sub	sp, sp, #44	; 0x2c
    35d4:	e5d0e000 	ldrb	lr, [r0]    ; (lr = GP_fpu_top value)
    35d8:	e59f004c 	ldr	r0, [pc, #76]	; 362c <log_fpu_c+0x74> (r0 = GP_fpu_sw address)
    35dc:	e3a04000 	mov	r4, #0
    35e0:	e1d0c0f0 	ldrsh	ip, [r0]    ; (ip = GP_fpu_sw value)
    35e4:	e1cd40f8 	strd	r4, [sp, #8]    ; (store 1.0 to stack)
    35e8:	e3a04000 	mov	r4, #0
    35ec:	e3a05101 	mov	r5, #1073741824	; 0x40000000 (2.0 high word)
    35f0:	e59f0038 	ldr	r0, [pc, #56]	; 3630 <log_fpu_c+0x78> (r0 = format string address)
    35f4:	e1cd41f0 	strd	r4, [sp, #16]   ; (store 2.0 to stack)
    35f8:	e59f5034 	ldr	r5, [pc, #52]	; 3634 <log_fpu_c+0x7c> (3.0 high word = 0x40080000)
    35fc:	e3a04000 	mov	r4, #0
    3600:	e58de000 	str	lr, [sp]    ; (store GP_fpu_top to stack)
    3604:	e1cd41f8 	strd	r4, [sp, #24]    ; (store 3.0 to stack)
    3608:	e59f5028 	ldr	r5, [pc, #40]	; 3638 <log_fpu_c+0x80> (4.0 high word = 0x40100000)
    360c:	e3a04000 	mov	r4, #0
    3610:	e58dc004 	str	ip, [sp, #4]    ; (store GP_fpu_sw to stack)
    3614:	e1cd42f0 	strd	r4, [sp, #32]    ; (store 4.0 to stack)
    3618:	ebfffffe 	bl	0 <printf>
    361c:	e28dd02c 	add	sp, sp, #44	; 0x2c (clean up stack)
    3620:	e8bd8030 	pop	{r4, r5, pc}    ; (return)
    3624:	00000000 	andeq	r0, r0, r0
    3628:	3ff00000 	svccc	0x00f00000
    362c:	00000000 	andeq	r0, r0, r0
    3630:	000017fc 	strdeq	r1, [r0], -ip
    3634:	40080000 	andmi	r0, r8, r0
    3638:	40100000 	andsmi	r0, r0, r0

Oh, wait, Paeryn, did you mean that the double values need to be in the stack at absolutely 8-byte aligned addresses? That may actually be my problem, I am calling this routine from ASM with no regard to what the SP register alignment is at the time of the call. I'll experiment next with aligning the stack pointer before this call to an 8-byte boundary.

Pate

[Pate]

Yay, that 8-byte stack alignment was my problem! Result after fixing the stack alignment before the call:

0x427b30c7 DBE3 TOP=0, sw=0000, 0=1.000000, 1=2.000000, 2=3.000000, 3=4.000000

So, it turned out that my question was not that much C/C++ -related after all, it was caused by an ASM/C interoperability issue. Special thanks to Paeryn, and sorry for wasting everyone's time...

Pate

[Paeryn]

The AAPCS specifies that the stack has to be 8 byte aligned at any public interface (ie function calls). printf will have realigned itself at the point it came to reading the doubles causing it to be offset from where they were.

Usually you'll get away with not aligning it properly for ages as a lot of functions won't care, but it then breaks something further down the line away from where the error really is.

Glad you've got it working now.

[PeterO]

@PeterO: Yes, you are probably right that I have not mentioned something relevant to my scenario, but the problem is that I don't know what might be the relevant parts. Perhaps the fact that I am calling this C log_fpu_c() routine from an ASM routine? I am calling various other C routines from ASM without problems, so that should not be relevant.

Well it seems it was relevant. To be honest I think you should have mentioned the fact that you were doing bits of ASM at the very start !

Glad it's fixed.

PeterO

[Pate]

@Paeryn: Thanks, it looks like I have completely missed that 8-byte alignment part of the AAPCS! Very embarrassing... Or perhaps I have just forgotten all about it as it has not bitten me until now? Anyways, I'll be sure to remember it from now on.

@PeterO: Yes, you are correct that I should have immediately mentioned that I am calling this routine from ASM. It just did not occur to me at all, as I am pretty much calling everything from ASM all the time. Again, sorry about that.

Happy Midsummer celebration everyone!

Pate