Opened 10 years ago

Closed 10 years ago

Last modified 14 months ago

#3904 closed bug (fixed)

Bug in shipped gcc makes profiling lose resolution

Reported by: augustss Owned by: igloo
Priority: high Milestone: 6.12.2
Component: Build System (make) Version: 6.12.1
Keywords: Cc:
Operating System: Windows Architecture: x86
Type of failure: None/Unknown Test Case:
Blocked By: Blocking:
Related Tickets: Differential Rev(s):
Wiki Page:

Description

When profiling on Windows the BEGIN_SAMPLE/END_SAMPLE do not contain a fractional part in the time information. As far as I can tell its a bug in gcc. I've included some C code that shows the problem.

Attachments (1)

c.c (907 bytes) - added by augustss 10 years ago.
C code to show the problem

Download all attachments as: .zip

Change History (10)

Changed 10 years ago by augustss

Attachment: c.c added

C code to show the problem

comment:1 Changed 10 years ago by augustss

Why is the prining so complex anyway, why not just

fprintf(..., "%s %.02f\n", ..., sampleValue);

?

comment:2 in reply to:  1 Changed 10 years ago by simonmar

Replying to augustss:

Why is the prining so complex anyway, why not just

fprintf(..., "%s %.02f\n", ..., sampleValue);

?

This is the patch that did it:

Tue May 11 19:36:10 BST 2004  panne
  * [project @ 2004-05-11 18:36:10 by panne]
  Make the printing of samples really locale-independent
    {
    hunk ./ghc/rts/ProfHeap.c 2
    - * $Id: ProfHeap.c,v 1.51 2004/03/19 23:20:20 panne Exp $
    + * $Id: ProfHeap.c,v 1.52 2004/05/11 18:36:10 panne Exp $
    hunk ./ghc/rts/ProfHeap.c 35
    +#include <math.h>
    hunk ./ghc/rts/ProfHeap.c 386
    +static void
    +printSample(rtsBool beginSample, StgDouble sampleValue)
    +{
    +    StgDouble fractionalPart, integralPart;
    +    fractionalPart = modf(sampleValue, &integralPart);
    +    fprintf(hp_file, "%s %d.%02d\n",
    +            (beginSample ? "BEGIN_SAMPLE" : "END_SAMPLE"),
    +            (int)integralPart, (int)(fractionalPart * 100 + 0.5));
    +}
    +
    hunk ./ghc/rts/ProfHeap.c 457
    -    fprintf(hp_file, "BEGIN_SAMPLE 0.00\n");
    -    fprintf(hp_file, "END_SAMPLE 0.00\n");
    +    printSample(rtsTrue, 0);
    +    printSample(rtsFalse, 0);
    hunk ./ghc/rts/ProfHeap.c 500
    -    fprintf(hp_file, "BEGIN_SAMPLE %0.2f\n", seconds);
    -    fprintf(hp_file, "END_SAMPLE %0.2f\n", seconds);
    +    printSample(rtsTrue, seconds);
    +    printSample(rtsFalse, seconds);
    hunk ./ghc/rts/ProfHeap.c 597
    +    (void)p;   /* keep gcc -Wall happy */
    hunk ./ghc/rts/ProfHeap.c 744
    -    fprintf(hp_file, "BEGIN_SAMPLE %0.2f\n", census->time);
    +    printSample(rtsTrue, census->time);
    hunk ./ghc/rts/ProfHeap.c 757
    -   fprintf(hp_file, "END_SAMPLE %0.2f\n", census->time);
    +   printSample(rtsFalse, census->time);
    hunk ./ghc/rts/ProfHeap.c 837
    -    fprintf(hp_file, "END_SAMPLE %0.2f\n", census->time);
    +    printSample(rtsFalse, census->time);
    }

I guess the problem is that the decimal point is not necessarily a '.'.

It looks like a later patch changed the types to StgWord64, which tickled the bug in gcc.

comment:3 Changed 10 years ago by augustss

Switching back to using (unsigned) int seems like the simplest fix then.

comment:4 in reply to:  3 Changed 10 years ago by simonmar

Replying to augustss:

Switching back to using (unsigned) int seems like the simplest fix then.

The patch that introduced the 64-bit values was:

Mon Sep 11 23:32:10 BST 2006  Ian Lynagh <igloo@earth.li>
  * Fix ~2000 second profiling time wrapping bug
    {
    hunk ./rts/ProfHeap.c 389
    -    fprintf(hp_file, "%s %d.%02d\n",
    +    fprintf(hp_file, "%s %" FMT_Word64 ".%02" FMT_Word64 "\n",
    hunk ./rts/ProfHeap.c 391
    -            (int)integralPart, (int)(fractionalPart * 100));
    +            (StgWord64)integralPart, (StgWord64)(fractionalPart * 100));
    hunk ./rts/posix/GetTime.c 47
    -    return (t.ru_utime.tv_sec * TICKS_PER_SECOND + [_$_]
    +    return ((Ticks)t.ru_utime.tv_sec * TICKS_PER_SECOND + [_$_]
    hunk ./rts/posix/GetTime.c 55
    -    return (tv.tv_sec * TICKS_PER_SECOND +
    +    return ((Ticks)tv.tv_sec * TICKS_PER_SECOND +
    hunk ./rts/posix/GetTime.c 123
    -    return (ts.tv_sec * TICKS_PER_SECOND + [_$_]
    +    return ((Ticks)ts.tv_sec * TICKS_PER_SECOND + [_$_]
    }

I can see that the changes to GetTime were necessary to avoid overflowing 32-bit integers (TICKS_PER_SECOND==1000000), but I don't see why we need to use StgWord64 in printSample, since the values there are seconds, not microseconds. Ian, any idea why this was done?

comment:5 Changed 10 years ago by igloo

With this C file:

#include <stdio.h>

int main(void)
{
    printf("A %lld\n", (long long int)(20));
    printf("B %lld\n", (long long int)(50));
    printf("C %lld %lld\n",
            (long long int)(20),
            (long long int)(50));
    printf("D %lld %lld %lld %lld %lld %lld %lld %lld\n",
            (long long int)(10),
            (long long int)(20),
            (long long int)(30),
            (long long int)(40),
            (long long int)(50),
            (long long int)(60),
            (long long int)(70),
            (long long int)(80));
    printf("E %lld %lld\n",
            (long long int)(-1),
            (long long int)(50));
    return 0;
}

Expected:

A 20
B 50
C 20 50
D 10 20 30 40 50 60 70 80
E -1 50

With the mingw gcc:

A 20
B 50
C 20 0
D 10 0 20 0 30 0 40 0
E -1 -1

with both gcc 3.4.5 and gcc 4.4.0.

comment:6 Changed 10 years ago by igloo

Milestone: 6.12.2
Priority: normalhigh

comment:7 Changed 10 years ago by igloo

Owner: set to igloo

comment:8 Changed 10 years ago by igloo

Resolution: fixed
Status: newclosed

Fixed in HEAD and 6.12:

Sat Mar 27 18:21:26 GMT 2010  Ian Lynagh <igloo@earth.li>
  * Fix the format specifier for Int64/Word64 on Windows
  mingw doesn't understand %llu/%lld - it treats them as 32-bit rather
  than 64-bit. We use %I64u/%I64d instead.

I haven't looked at whether we actually need 64bit ints in this particular case, but this nevertheless fixes the problem, and also fixes the other places where we print 64bit ints in the RTS.

comment:9 Changed 14 months ago by bgamari

Component: Build SystemBuild System (make)

The new Hadrian build system has been merged. Relabeling the tickets concerning the legacy make build system to prevent confusion.

Note: See TracTickets for help on using tickets.