VBCC Profiling options ?

[ReadOnlyCat]

Hello there,

VBCC seems to have support for profiling (as its doc indicates: http://phoenix.owl.de/vbcc/docs/vbcc.pdf) but the documentation section on profiling unashamedly states:

14.9.13 Profiling
FIXME: To be written.

There seems to be a

-prof

option but nowhere in the doc is it indicated how to use it.

I do not have an immediate need for it but as I am gearing up with my C coding at the moment on the Amiga I know will soon want to do some form of profiling. Of course, there is always the good old trick of changing the background color upon entry/exit of routines but since have long been corrupted by the joys of VTunes/DotTrace professional profiling tools at work I would appreciate more precise tooling than just color changes.

Does anyone know how this option operates in VBCC?

Thanks in advance, and please, stay safe!

[phx]

It works similar to gcc profiling. When compiled with the -prof option the executable will write a file with profiling data on exit, called mon.out. These profiling data can be analyzed with the vprof tool.

And thanks for the reminder about the missing section in the doc. Somehow it was overlooked since decades.

[ReadOnlyCat]

Oh, wow, this is just perfect.

As usual, thanks for your answer Phx!
Take care.

[ReadOnlyCat]

I am using 0.9g (from http://sun.hasenbraten.de/vbcc/index.php?view=main) and

vprof

seems to not like the output format of

mon.out

.

The Amiga executable was compiled with:

vc +aos68k -prof -I$NDK_INC -lamiga "main.c" -o "test"

After I run the

test

Amiga executable, it actually outputs two files:

-rw-r--r--  1 laurent  staff    124 26 Apr 16:28 mon.out
-rw-r--r--  1 laurent  staff     33 26 Apr 16:28 mon.out.uaem
-rwxr-xr-x  1 laurent  staff  13344 26 Apr 16:28 test

But running

vprof

on the first one gives:

$ vprof mon.out
vprof: mon.out: Corrupted file format.

The VBCC config line I am using is the following:

-cc=vbccm68k -quiet -hunkdebug %s -o= %s %s -O=%ld -I$VBCC/targets/m68k-amigaos/include -c99

The content of the

mon.out

file:

$ hexdump -Cv mon.out
00000000  49 6e 69 74 69 61 6c 69  7a 65 00 00 00 00 00 01  |Initialize......|
00000010  00 00 10 ed 00 00 10 ed  6d 61 69 6e 00 00 00 00  |........main....|
00000020  00 00 00 01 00 75 ff e7  00 32 5c f3 54 65 72 6d  |.....u...2\.Term|
00000030  69 6e 61 74 65 00 00 00  00 00 00 01 00 00 01 fc  |inate...........|
00000040  00 00 01 fc 53 70 6c 69  74 42 79 43 6f 75 6e 74  |....SplitByCount|
00000050  52 6f 75 6e 64 65 64 00  00 00 00 02 00 00 03 81  |Rounded.........|
00000060  00 00 03 81 50 6c 6f 74  50 69 78 65 6c 00 00 00  |....PlotPixel...|
00000070  00 00 18 00 00 43 8c 8a  00 43 8c 8a              |.....C...C..|
0000007c

[phx]

Oh. I see the problem! The profiling output was generated by a 32-bit big-endian machine while you are probably running vprof natively on a 64-bit little-endian machine? That doesn't work.

It's my fault, of course, because I didn't design the mon.out format to be portable across different architectures.

Now the only solution would be to add options to vprof to define endianess and "long int" size for the input file. This information should have been in the header of mon.out if I did it right...

[ReadOnlyCat]

Originally Posted by phx

Oh. I see the problem! The profiling output was generated by a 32-bit big-endian machine while you are probably running vprof natively on a 64-bit little-endian machine? That doesn't work.

It's my fault, of course, because I didn't design the mon.out format to be portable across different architectures.

Now the only solution would be to add options to vprof to define endianess and "long int" size for the input file. This information should have been in the header of mon.out if I did it right...

Ah, indeed macOS is x64 so definitely little endian and LP64 to boot.

I hacked

vprof

's sources to use

uint32_t

members in

struct profdata

so the program now assumes the incoming data is always 32 bits and I got it to recognize the output:

  %     total   local                local      total
 time  seconds seconds     calls    ms/call    ms/call  name
16.12 1090.81 2335.26  16777216      0.139      0.065  main
13.90 2013.53 2013.53  33554432      0.060      0.060  SplitByCountRounded
13.48 1836.21 1952.54 2335257088      0.001      0.001  
11.75 1953.46 1702.39 2013528064      0.001      0.001  
 7.82 1768.71 1132.02 4244701184      0.000      0.000  
 4.29  620.95  620.95  16777216      0.037      0.037  Initialize
 3.33  482.95  482.95   1572864      0.307      0.307  PlotPixel
 0.00 1852.40    0.00 620953600      0.000      0.003  
 0.00    0.00    0.00 482951936      0.000      0.000  
29.31 4244.70 4244.70  16777216      0.253      0.253  Terminate

The data is garbage because I have not yet converted to little endian.

The changes I made are super localized, if you want them, just ping me.

[ReadOnlyCat]

I was actually miscalculating the remainder of

struct profdata

which was the cause of the multiple spurious entries above. I fixed that and the final result with endianness corrected now looks as it should:

  %     total   local                local      total
 time  seconds seconds     calls    ms/call    ms/call  name
57.44 1137.25 1137.25   1573072      0.723      0.723  PlotPixel
42.53 1979.99  842.11       464   1814.888   4267.221  main
 0.01    0.29    0.29       720      0.407      0.407  SplitByCountRounded
 0.01    0.21    0.21       464      0.445      0.445  Initialize
 0.01    0.13    0.13       464      0.281      0.281  Terminate

\(^^)/

My (small) changes are available for inspection anytime.

[ReadOnlyCat]

Thinking about it, it should be possible to use the following heuristic to determine the format of an existing profile.

1- look for the string

"main"

in the file.
2- once found, we know that the

ncalls

value for it is going to be exactly

one

so we know that the next 4 to 8 bytes are going to contain the value 1 in big or little endian
3- we skip all zeroes after the name until we encounter a

0x01

byte
4- if that byte is aligned on a multiple of 2^n - 1, we know the format is big endian
5- if that byte is aligned on a multiple of 2^n, the format is little endian

Determining the size of each field (32 or 64 bit) is a bit trickier because the other fields have much less predictable values but it should be possible to easily detect the next and/or previous function name after or before

main

and thus deduce the size of

struct profdata

and of its members.

Obviously it would be better to change the format to include a proper header but this would work in the meantime and would preserves the readability of old profiles even after the format changes.

[phx]

Yes, this might work. But when I have to touch vprof.c anyway I would rather go the safe route and add an option to let the user specify the format.

[Warty]

ReadOnlyCat: any chance you could throw up a mac build of your version?