Bug in printf with long long handling

pedward · 2012-06-12 00:16

As a simple test, I modified the hello.c as follows:

 #include <stdio.h>
 #include <propeller.h>
  int main(void)
 {
     long long n = 1;
     printf("Hello World\n");
     while(1) {
         waitcnt(CLKFREQ/10+CNT);
         printf("Hello World %x %x\n", n, n);

         n+=0x0FFFFFFF;
     }
     return 0;
 }

The result is garbage for the second value. Now, %x only handles longs, but it appears that the stack is not properly managed by the printf function.

What happens:

String is pushed onto stack
Low long of n is pushed
High long of n is pushed
Low long of n is pushed
High long of n is pushed
printf is called

Here's the PASM listing:

 

17:hello.c       ****         printf("Hello World %x %x\n", n, n);
   55                      .loc 1 17 0 discriminator 1
   56 0068 009C3C08         wrlong    .LC4, sp
   57 006c 0000BCA0         mov    r7, sp
   58 0070 0400FC80         add    r7, #4
   59 0074 0000BCA0         mov    r6, r14

   60 0078 0800FC84         sub    r6, #8
   61 007c 0000BC08         rdlong    r6, r6
   62 0080 00003C08         wrlong    r6, r7
   63 0084 0400FC80         add    r7, #4
   64 0088 0000BCA0         mov    r6, r14
   65 008c 0400FC84         sub    r6, #4
   66 0090 0000BC08         rdlong    r6, r6
   67 0094 00003C08         wrlong    r6, r7
   68 0098 0000BCA0         mov    r7, sp
   69 009c 0C00FC80         add    r7, #12
   70 00a0 0000BCA0         mov    r6, r14
   71 00a4 0800FC84         sub    r6, #8
   72 00a8 0000BC08         rdlong    r6, r6
   73 00ac 00003C08         wrlong    r6, r7

   74 00b0 0400FC80         add    r7, #4
   75 00b4 0000BCA0         mov    r6, r14
   76 00b8 0400FC84         sub    r6, #4
   77 00bc 0000BC08         rdlong    r6, r6
   78 00c0 00003C08         wrlong    r6, r7
   79 00c4 0000FC5C         jmpret    lr,#_printf

The observed behavior is the low long of n is displayed with first %x, but for the second %x it is gibberish. The expected behavior is that the low long of n should be displayed with spaces separating.

As a test, I replaced the second n with 0 and got the expected result, 4 items are placed on the stack in that instance.

If I just put n as the argument, I get similar gibberish, so it's consuming both longs.

My original intent was to print the high long using this syntax:


        printf("Hello World %x %x\n", *(&n+4), n);

Dave Hein · 2012-06-12 04:20

Try %llx..

ersmith · 2012-06-12 05:27

gcc actually parses printf strings -- for example, it will replace printf("hello, world\n") with puts("hello, world"). So if you give it a string that doesn't match its arguments, the results are undefined. That's in accordance with the C standard.

As Dave said, %llx can be used to print a long long. If you really want to print the two halves separately, use casts and do something like:

printf("value = %x %x", (long)n, (long)(n>>32));

pedward · 2012-06-12 11:02

%llx doesn't work, the results are that it prints the string "lx", the correct syntax is "%xll" where ll follows the integer conversion. This is not supported by either the simple printf or the GCC provided printf.

If you look at the assembly listing, you will see that GCC didn't do any magic, it did as it should and passed 5 longs on the stack. The problem is in printf handling the passed variables.

I tested with the "not" simple printf, and it does the same thing.

If I pass "n, 0" as the parameters, the first invocation of printf prints "1 0", then each subsequent invocation prints garbage for the second argument.

The output for ersmiths suggestion results in garbage in the "(long) (n>>32)" position.

   17:hello.c       ****         printf("Hello World %x %x\n", (long)(n>>32), (long)n);

   63                      .loc 1 17 0 discriminator 1

  64 0078 0000BCA0         mov    r7, r14

   65 007c 0400FC84         sub    r7, #4
   66 0080 0000BC08         rdlong    r6, r7
   67 0084 0000BCA0         mov    r12, r6
   68 0088 0000FC38         sar    r12, #0
   69 008c 0000BC08         rdlong    r7, r7
   70 0090 0000BCA0         mov    r13, r7
   71 0094 1F00FC38         sar    r13, #31
   72 0098 0000BCA0         mov    r5, r12
   73 009c 0000BCA0         mov    r7, r14
   74 00a0 0800FC84         sub    r7, #8
   75 00a4 0000BC08         rdlong    r6, r7

   76 00a8 009C3C08         wrlong    .LC4, sp
   77 00ac 0000BCA0         mov    r7, sp
   78 00b0 0400FC80         add    r7, #4
   79 00b4 00003C08         wrlong    r5, r7
   80 00b8 0000BCA0         mov    r7, sp
   81 00bc 0800FC80         add    r7, #8
   82 00c0 00003C08         wrlong    r6, r7
   83 00c4 0000FC5C         jmpret    lr,#_printf

The code above shows quite clearly that there is some screwy stuff going on with printf and the stack. I would bet that the stack will keep growing until the program crashes.

David Betz · 2012-06-12 11:56

I just ran this with Eric's suggested change and it seemed to work fine for me. Here is my modified code and the results of running it. This will not work with simple_printf because that doesn't support the long long type as far as I know.

 #include <stdio.h>
 #include <propeller.h>
  int main(void)
 {
     long long n = 1;
     printf("Hello World\n");
     while(1) {
         waitcnt(CLKFREQ/10+CNT);
         printf("Hello World %llx %llx\n", n, n);

         n+=0x0FFFFFFF;
     }
     return 0;
 }

david-betzs-macbook-pro:propgcc dbetz$ propeller-elf-gcc -Os -o longlong.elf longlong.c
david-betzs-macbook-pro:propgcc dbetz$ propeller-load -bc3 longlong.elf -r -t
Propeller Version 1 on /dev/cu.usbserial-A3TNQL8K
Loading longlong.elf to hub memory
13932 bytes sent                  
Verifying RAM ... OK
[ Entering terminal mode. Type ESC or Control-C to exit. ]
Hello World
Hello World 1 1
Hello World 10000000 10000000
Hello World 1fffffff 1fffffff
Hello World 2ffffffe 2ffffffe
Hello World 3ffffffd 3ffffffd
Hello World 4ffffffc 4ffffffc
Hello World 5ffffffb 5ffffffb
Hello World 6ffffffa 6ffffffa
Hello World 7ffffff9 7ffffff9
Hello World 8ffffff8 8ffffff8
Hello World 9ffffff7 9ffffff7
Hello World affffff6 affffff6
Hello World bffffff5 bffffff5
Hello World cffffff4 cffffff4
Hello World dffffff3 dffffff3
Hello World effffff2 effffff2
Hello World fffffff1 fffffff1
Hello World 10ffffff0 10ffffff0
Hello World 11fffffef 11fffffef
Hello World 12fffffee 12fffffee
Hello World 13fffffed 13fffffed
Hello World 14fffffec 14fffffec
Hello World 15fffffeb 15fffffeb
Hello World 16fffffea 16fffffea
Hello World 17fffffe9 17fffffe9
Hello World 18fffffe8 18fffffe8
Hello World 19fffffe7 19fffffe7
Hello World 1afffffe6 1afffffe6
Hello World 1bfffffe5 1bfffffe5

pedward · 2012-06-12 12:49

I'm using the latest source from the repo, and unclicking "simple printf" doesn't yield any different behavior.

David Betz · 2012-06-12 12:51

pedward wrote: »

I'm using the latest source from the repo, and unclicking "simple printf" doesn't yield any different behavior.

I'm also using the latest source but compiling with the command line tools. Maybe Steve will try this with SimpleIDE and let us know what he finds.

pedward · 2012-06-12 13:01

If you use COG memory model, it ignores the "don't use simple printf" compile option. Regular printf only works in LMM or XMM memory model.

When I changed to LMM and "standard printf" the results were as expected.

That said, there is still a bug.

In COG MM, using simple printf, when casted to a long and shifted, the results are not as expected.

In LMM, using simple printf, when casted to a long and shifted, the results are as expected.

Clearly there is something wrong with simple printf in COG MM.

David Betz · 2012-06-12 13:14

pedward wrote: »

If you use COG memory model, it ignores the "don't use simple printf" compile option. Regular printf only works in LMM or XMM memory model.

When I changed to LMM and "standard printf" the results were as expected.

That said, there is still a bug.

In COG MM, using simple printf, when casted to a long and shifted, the results are not as expected.

In LMM, using simple printf, when casted to a long and shifted, the results are as expected.

Clearly there is something wrong with simple printf in COG MM.

I'm surprised that printf works at all in the COG memory model.

ersmith · 2012-06-12 13:21

pedward wrote: »

%llx doesn't work, the results are that it prints the string "lx", the correct syntax is "%xll" where ll follows the integer conversion. This is not supported by either the simple printf or the GCC provided printf.

No, "%llx" is definitely the correct syntax, and it's supported by the standard printf. The simple printf, however, does not handle 64 bit integers.

I note that in your assembly code there's a "jmpret lr, #_printf". That implies that you're compiling for the COG memory model, which is pretty significant, because it uses a different library. That library only has the simple printf; in fact it's a stripped down version of the full printf. So 64 bits aren't handled.

jazzed · 2012-06-12 13:34

The printf variations are described in the library document.

http://propgcc.googlecode.com/hg/doc/Library.html#printf

ersmith · 2012-06-12 13:35

The following program seems to work correctly for me even in COG mode:

#include <stdio.h>
#include <propeller.h>

void
main()
{

    long long test;

    test = 0x12345678abcdef0LL;

    printf("test = %x %x\n", (unsigned int)test, (unsigned int)(test>>32));
    test++;
    printf("test2 = %x %x\n", (unsigned int)test, (unsigned int)(test>>32));
}

pedward · 2012-06-12 14:47

I tried running that code, but SIDE locked up when it was in terminal mode, I assume because it was in a blocking read, hung, because the program didn't print enough data to the console.

I tried your same syntax in the hello.c program and it still doesn't work properly.

I would appreciate it if people would try to replicate my findings with the code I provided above, instead of telling me 5 different ways of trying to do it otherwise. My syntax isn't wrong, the compiled code is not working correctly. I want to fix or document this problem, not ignore it.

The first step in fixing something is to replicate the result, given the input. If the input is insufficient to replicate the result, then goto 0.

I have narrowed it down to simple printf not behaving correctly in COG mode. The "(unsigned int)(n>>32)" syntax DOES NOT work in the hello.c example I cited above.

I'm not trying to be contrary, I'm trying to get to the bottom of what I see as a bug, because it doesn't pass the simplest of examples.

This was prompted by the 64bit math thread, I wanted to simply demonstrate 64bit variable handling, and it has failed.

jazzed · 2012-06-12 15:44

pedward wrote: »

I would appreciate it if people would try to replicate my findings with the code I provided above, instead of telling me 5 different ways of trying to do it otherwise. My syntax isn't wrong, the compiled code is not working correctly. I want to fix or document this problem, not ignore it.

I agree. I've tried all the examples here and the only ones i can get to work are:
Eric's simple_printf LMM example, and peward's non simple_printf LMM example.

These were all run with simpleide on linux (pita not being able to simply disable output).

Here are some output samples:

SimpleIDE Eric's example:

test = 8ABCDEF0 1234567
test2 = 8ABCDEF1 1234567

peward example with no simple_printf on LMM

Hello World fffffff01 fffffff01
Hello World 100fffff00 100fffff00
Hello World 101ffffeff 101ffffeff
Hello World 102ffffefe 102ffffefe
Hello World 103ffffefd 103ffffefd
Hello World 104ffffefc 104ffffefc
Hello World 105ffffefb 105ffffefb
Hello World 106ffffefa 106ffffefa

peward example with simple_printf on LMM

Hello World
Hello World 1 0
Hello World 10000000 0
Hello World 1FFFFFFF 0
Hello World 2FFFFFFE 0
Hello World 3FFFFFFD 0
Hello World 4FFFFFFC 0
Hello World 5FFFFFFB 0
Hello World 6FFFFFFA 0
Hello World 7FFFFFF9 0
Hello World 8FFFFFF8 0
Hello World 9FFFFFF7 0
...
Hello World FFFFFFF1 0
Hello World FFFFFF0 1
Hello World 1FFFFFEF 1
Hello World 2FFFFFEE 1
Hello World 3FFFFFED 1
Hello World 4FFFFFEC 1

peward example with COG mode

Hello World
Hello World lx lx
Hello World lx lx
Hello World lx lx
Hello World lx lx
Hello World lx lx
Hello World lx lx
Hello World lx lx
Hello World lx lx
Hello World lx lx
Hello World lx lx

pedward · 2012-06-12 16:10

There is definitely something wonky with the printf in COG MM. I don't think it's properly fetching items off the stack.

Where is the source to the simple printf located? I'm assuming that there are multiple libraries for it, one for COG MM and one for xMMy?

ersmith · 2012-06-12 17:07

Thank you for posting the bug report, but I can't reproduce the problem.

I tried compiling your sample program (the first one in the thread) exactly as given, and it worked for me. The code was:

#include <stdio.h>
#include <propeller.h>

int main(void)
 {
     long long n = 1;
     printf("Hello World\n");
     while(1) {
         waitcnt(CLKFREQ/10+CNT);
         printf("Hello World %x %x\n", n, n);
         n+=0x0FFFFFFF;
     }
     return 0;
 }

I don't have simple IDE. The command line I used to compile was:

propeller-elf-gcc -mcog -Os -o foo.cof foo.c

and the output was:

Hello World
Hello World 1 0
Hello World 10000000 0
Hello World 1fffffff 0
Hello World 2ffffffe 0
Hello World 3ffffffd 0
Hello World 4ffffffc 0
Hello World 5ffffffb 0
Hello World 6ffffffa 0
Hello World 7ffffff9 0
Hello World 8ffffff8 0
Hello World 9ffffff7 0
Hello World affffff6 0
Hello World bffffff5 0
Hello World cffffff4 0
Hello World dffffff3 0
Hello World effffff2 0
Hello World fffffff1 0
Hello World ffffff0 1
Hello World 1fffffef 1

Note that the code as given is not legal C, since we're passing 2 long longs in to printf but the format string is told to expect only unsigned ints. So in theory the results could be undefined and I just happen to be getting the right answer where you are not. We could try modifying the code to be strictly C compliant, which would be:

#include <stdio.h>
#include <propeller.h>

int main(void)
 {
     long long n = 1;
     printf("Hello World\n");
     while(1) {
         waitcnt(CLKFREQ/10+CNT);
         printf("Hello World %x %x\n", (unsigned int)(n>>32), (unsigned int)n);
         n+=0x0FFFFFFF;
     }
     return 0;
 }

Does that work for you?

pedward · 2012-06-12 17:20

ersmith, no, that syntax does not work, per message #13.

ersmith · 2012-06-12 17:22

OK, I think I'm starting to see what may be going on here, and I think it's a problem with code generation of 64 bit constants in -mcog mode. In some circumstances the compiler will put a 64 bit constant into memory like:

    .balign    4
.LC1
    long    -1698898192
    long    305419896

and then loads it with something like:

    rdlong r13, .LC2
    ....
.LC2
    long    .LC1+4

But this requires that .LC1 must be in hub memory in order to work properly, and it looks like in -mcog mode the compiler puts it into cog memory.

It should just emit

    mov r13, .LC1+4

directly in -mcog mode. I'll look into it.

pedward · 2012-06-12 17:30

Here's a dump of the hello.c with the >>32 syntax:

   1                      .text
   2                  .Ltext0
   3                      .data
   4                      .balign    4
   5                  .LC0
   6 0000 48656C6C         .ascii "Hello World\0"
   6      6F20576F 
   6      726C6400 
   7                      .balign    4
   8                  .LC3
   9 000c 48656C6C         .ascii "Hello World %x %x\12\0"
   9      6F20576F 
   9      726C6420 
   9      25782025 
   9      780A00
  10 001f 00               .text
  11                      .balign    4
  12                      .global    _main
  13                  _main
  14                  .LFB0
  15                      .file 1 "hello.c"
   1:hello.c       **** /*
   2:hello.c       ****  * This demo uses waitcnt instead of sleep so it will fit in a COG.
   3:hello.c       ****  * It also repeats printing every 200ms and prints the iteration.
   4:hello.c       ****  * Some computers may not be fast enough for the terminal to catch
   5:hello.c       ****  * the serial input after loading the Propeller, so you may not see
   6:hello.c       ****  * "Hello World 1", but you will see something on the terminal.
   7:hello.c       ****  */
   8:hello.c       **** #include <stdio.h>
   9:hello.c       **** #include <propeller.h>
  10:hello.c       **** 
  11:hello.c       **** int main(void)
  12:hello.c       **** {
  16                      .loc 1 12 0
  17 0000 0400FC84         sub    sp, #4
  18                  .LCFI0
  19 0004 00003C08         wrlong    r8, sp
  20                  .LCFI1
  21 0008 0400FC84         sub    sp, #4
  22                  .LCFI2
  23 000c 00003C08         wrlong    r12, sp
  24                  .LCFI3
  25 0010 0400FC84         sub    sp, #4
  26                  .LCFI4
  27 0014 00003C08         wrlong    r13, sp
  28                  .LCFI5
  29 0018 0400FC84         sub    sp, #4
  30                  .LCFI6
  31 001c 00003C08         wrlong    r14, sp
  32                  .LCFI7
  33 0020 0400FC84         sub    sp, #4
  34                  .LCFI8
  35 0024 00003C08         wrlong    lr, sp
  36                  .LCFI9
  37 0028 0000BCA0         mov    r14, sp
  38                  .LCFI10
  39 002c 1400FC84         sub    sp, #20
  40                  .LCFI11
  13:hello.c       ****     long long n = 1;
  41                      .loc 1 13 0
  42 0030 0100FCA0         mov    r6, #1
  43 0034 0000BCA0         mov    r7, r14
  44 0038 0800FC84         sub    r7, #8
  45 003c 00003C08         wrlong    r6, r7
  46 0040 0000BCA0         mov    r7, r14
  47 0044 0400FC84         sub    r7, #4
  48 0048 0000FCA0         mov    r6, #0
  49 004c 00003C08         wrlong    r6, r7
  14:hello.c       ****     printf("Hello World\n");
  50                      .loc 1 14 0
  51 0050 4C00BCA0         mov    r7, .LC1
  52 0054 0000BCA0         mov    r0, r7
  53 0058 0000FC5C         jmpret    lr,#_puts
  54                  .L2
  15:hello.c       ****     while(1) {
  16:hello.c       ****         waitcnt(CLKFREQ/4+CNT);
  55                      .loc 1 16 0 discriminator 1
  56 005c 4D00BCA0         mov    r7, .LC2
  57 0060 0000BC08         rdlong    r7, r7
  58 0064 0000BCA0         mov    r6, r7
  59 0068 0200FC28         shr    r6, #2
  60 006c 0000BCA0         mov    r7, CNT
  61 0070 0000BC80         add    r7, r6
  62 0074 0000FCF8         waitcnt    r7,#0
  17:hello.c       ****         printf("Hello World %x %x\n", (unsigned int)(n), (unsigned int)(n>>32));
  63                      .loc 1 17 0 discriminator 1
  64 0078 0000BCA0         mov    r7, r14
  65 007c 0800FC84         sub    r7, #8
  66 0080 0000BC08         rdlong    r5, r7
  67 0084 0000BCA0         mov    r7, r14
  68 0088 0400FC84         sub    r7, #4
  69 008c 0000BC08         rdlong    r6, r7
  70 0090 0000BCA0         mov    r12, r6
  71 0094 0000FC38         sar    r12, #0
  72 0098 0000BC08         rdlong    r7, r7
  73 009c 0000BCA0         mov    r13, r7
  74 00a0 1F00FC38         sar    r13, #31
  75 00a4 0000BCA0         mov    r6, r12
  76 00a8 009C3C08         wrlong    .LC4, sp
  77 00ac 0000BCA0         mov    r7, sp
  78 00b0 0400FC80         add    r7, #4
  79 00b4 00003C08         wrlong    r5, r7
  80 00b8 0000BCA0         mov    r7, sp
  81 00bc 0800FC80         add    r7, #8
  82 00c0 00003C08         wrlong    r6, r7
  83 00c4 0000FC5C         jmpret    lr,#_printf
  18:hello.c       ****         n+=0xFFFFFFF;
  84                      .loc 1 18 0 discriminator 1
  85 00c8 0000BCA0         mov    r7, r14
  86 00cc 0800FC84         sub    r7, #8
  87 00d0 0000BC08         rdlong    r5, r7
  88 00d4 0000BCA0         mov    r7, r14
  89 00d8 0400FC84         sub    r7, #4
  90 00dc 0000BC08         rdlong    r6, r7
  91 00e0 4F00BCA0         mov    r3, .LC5
  92 00e4 5100BCA0         mov    r7, .LC6
  93 00e8 0000BC08         rdlong    r4, r7
  94 00ec 0000BCA0         mov    r7, r5
  95 00f0 0000BC80         add    r7, r3
  96 00f4 00003C85         cmp    r7, r5 wc
  97 00f8 0000FCA0         mov    r2, #0
  98 00fc 0100FC70         muxc    r2,#1
  99 0100 0000BCA0         mov    r8, r6
 100 0104 0000BC80         add    r8, r4
 101 0108 0000BCA0         mov    r6, r2
 102 010c 0000BC80         add    r6, r8
 103 0110 0000BCA0         mov    r8, r6
 104 0114 0000BCA0         mov    r6, r14
 105 0118 0800FC84         sub    r6, #8
 106 011c 00003C08         wrlong    r7, r6
 107 0120 0000BCA0         mov    r6, r14
 108 0124 0400FC84         sub    r6, #4
 109 0128 00003C08         wrlong    r8, r6
  19:hello.c       ****     }
 110                      .loc 1 19 0 discriminator 1
 111 012c 17007C5C         jmp    #.L2
 112                  .LFE0
 113                      .balign    4
 114                  .LC1
 115 0130 00000000         long    .LC0
 116                      .balign    4
 117                  .LC2
 118 0134 00000000         long    __clkfreq
 119                      .balign    4
 120                  .LC4
 121 0138 0C000000         long    .LC3
 122                      .balign    4
 123                  .LC5
 124 013c FFFFFF0F         long    268435455
 125 0140 00000000         long    0
 126                      .balign    4
 127                  .LC6
 128 0144 40010000         long    .LC5+4
 190                  .Letext0
 191                      .file 2 "/opt/parallax/propgcc/bin/../lib/gcc/propeller-elf/4.6.1/../../../../propeller-elf/includ

pedward · 2012-06-13 00:16

Well, this problem *may* have gone away by rebuilding the compiler. I just wrote and tested a sample program, after narrowing down the source, and printf is working as expected.

I was able to initialize a 64bit value and shift it to print the upper and lower longs. I'm in the process of rebuilding the compiler from scratch, my local repo was dorked and I had to re-clone the repo. I got half way through building the tools and it bombed out on the library. Oops, bombed out again, off to make another post...

ersmith · 2012-06-13 04:32

pedward wrote: »

Well, this problem *may* have gone away by rebuilding the compiler. I just wrote and tested a sample program, after narrowing down the source, and printf is working as expected.

No, rebuilding the compiler won't help -- there really is a bug in the initialization of 64 bit values in -mcog mode. It will only show up in certain circumstances, which is why I thought the issue was undefined behavior. The fix may take a little while, though.

Thanks for bringing this issue to our attention.

ersmith · 2012-06-13 09:48

I've checked in a fix for the 64 bit load problem, so rebuilding the compiler with the latest sources should fix it (assuming you're able to rebuild the compiler, of course, but that's an issue for another thread!)

Bug in printf with long long handling

Comments