Hello, FPC developers' list.

I tried to build the compiler with gprof profile code. In the compiler dir I executed:

make clean all OPT="-gl -pg"

As result of linking I have the next errors:
Linking .\pp.exe
pp.pas(224,1) Error: Import library not found for c
pp.pas(224,1) Error: Import library not found for gmon
pp.pas(224,1) Error: Import library not found for cygwin
pp.pas(224,1) Error: Import library not found for user32
pp.pas(224,1) Error: Import library not found for kernel32
pp.pas(224,1) Error: Import library not found for gcc
pp.pas(224,1) Error: Undefined symbol: _mcount
pp.pas(224,1) Error: Undefined symbol: __mcleanup
pp.pas(224,1) Error: Undefined symbol: _monstartup
pp.pas(224,1) Error: Undefined symbol: ___main
pp.pas(224,1) Error: Undefined symbol: _cygwin_crt0
pp.pas(224,1) Fatal: There were 11 errors compiling module, stopping

I understand that I need to help linker somehow to find some files. But I have no idea what does it need: c.lib or c.o or c.dll? Where should I obtain that files?

I tried to search our wiki:
http://wiki.freepascal.org/Profiling#FreePascal_profiler_support and I see that on windows some additional steps might be required but what steps is not written :)

Please help.

Btw, maybe a good idea to have the built-in easy profiler info support in the compiler. Compiler can surround each call by the code which measure the time and log it to the external file.

I have those files in c:\cygwin\lib. I don't know anymore what cygwin packages I installed to get them.

Last time I tried (a couple of months ago), I could compile Lazarus with profiling info, but the gprof output file remained empty, IIRC.

libc.a

Vincent

Hello Vincent,

VS> I have those files in c:\cygwin\lib. I don't know anymore what cygwin packages I VS> installed to get them.
VS> Last time I tried (a couple of months ago), I could compile Lazarus with profiling VS> info, but the gprof output file remained empty, IIRC.

I had used it one year ago for a project and I had to install mingw32 and cygwin and add the libs paths to the "other library" of the project. This is my search path for that project, maybe it helps:

C:\cygwin\bin\;C:\cygwin\lib\;C:\Mingw\lib\;C:\Mingw\lib\gcc\mingw32\3.4.5\

Obviously one of them is not needed ;)

...
After installing both cygwin and mingw I am able to build compiler with gprof support. I needed to pass libs path to the compiler

..\bin\i386-win32\make.exe clean all OPT="-gl -pg
-FlC:\cygwin\lib;C:\programming\mingw\lib;C:\programming\mingw\lib\gcc\mingw32\3.4.5"

I have attached compiler gprof output of compiler itself. Using output I was able to find and improve(?) 3 functions I found in output.

What I can't understand why the biggest %time has the lowest seconds. E.g: % cumulative self self total
time seconds seconds calls Ts/call Ts/call name 5.11 0.36 0.36
CCLASSES_TFPHASHLIST_$__INTERNALFIND$LONGWORD$SHORTSTRING$LONGINT$$LONGINT ...
0.14 7.05 0.01
fpc_shortstr_to_ansistr

As result I don't understand which functions must be anybody tried that before?

Best regards,
Paul Ishenin.

Paul Ishenin пишет:

What I can't understand why the biggest %time has the lowest seconds. E.g:

The second column is a cumulative time, i.e. sum of the time for the given function and everything above it.

As result I don't understand which functions must be reviewed at first. Have anybody tried that before?

I did, but using Linux+valgrind rather than cygwin+gprof. IMHO valgrind (in its callgrind flavour) outputs more useful profile information.
Some time ago I was able to optimize away about 20% of executed CPU instructions in the compiler, which however didn't decrease its execution time by any noticeable amount. So, going for another 20% will be a much more complicated task, beware.

Sergei

Hello Paul,

Friday, November 20, 2009, 6:08:28 PM, you wrote:

PI> What I can't understand why the biggest %time has the lowest seconds. E.g: PI> % cumulative self self total PI> time seconds seconds calls Ts/call Ts/call name PI> 5.11 0.36 0.36
PI> CCLASSES_TFPHASHLIST_$__INTERNALFIND$LONGWORD$SHORTSTRING$LONGINT$$LONGINT PI> ...
PI> 0.14 7.05 0.01
PI> fpc_shortstr_to_ansistr

Because that's it time, which is splitted with other functions called by itself, so discounted the time of the called functions the investigated function only spend a few seconds (self). Example:

procedure Dummy();
begin
  FillChar(P,$7FFFFFFF,0);
  FillChar(P,$7FFFFFFF,0);
  FillChar(P,$7FFFFFFF,0);
  FillChar(P,$7FFFFFFF,0);
end;

Dummy will get the highest cumulative time, but its (self) real time would be almost nothing.

PI> As result I don't understand which functions must be > Have anybody tried that before?

You must get the "calls", functions with more calls are usually the ones that would get more benefit from any optimization. Also look for functions (specially the basic ones) that spend too much time.

Sergei Gorelkin wrote

I did, but using Linux+valgrind rather than cygwin+gprof. IMHO valgrind (in its callgrind flavour) outputs more useful profile information. Some time ago I was able to optimize away about 20% of executed CPU instructions in the compiler, which however didn't decrease its execution time by any noticeable amount. So, going for another 20% will be a much more complicated task, beware.

Most of the time spent in the compiler is waiting for memory. Below are some numbers I collected with Shark (a sampling based profiler for Mac OS X) when compiling the compiler with itself and with DWARF debug info (DWARF adds a lot of individual data elements to the assembler output) on Mac OS X/i386:

Before r14137:
6.1% ppn19sl AGGAS_TGNUASSEMBLER_$__WRITETREE$TASMLIST 5.7% ppn19sl SYSTEM_SYSGETMEM_FIXED$LONGWORD$$POINTER 3.5% libSystem.B.dylib __bzero
2.7% ppn19sl CCLASSES_TFPHASHLIST_$__INTERNALFIND$LONGWORD$SHORTSTRING$LONGINT$$LONGINT 2.6% ppn19sl SYSTEM_TOBJECT_$__CLEANUPINSTANCE
2.2% libSystem.B.dylib __memcpy
2.1% ppn19sl SYSTEM_SYSFREEMEM_FIXED$PFREELISTS$PMEMCHUNK_FIXED$$LONGWORD 1.7% ppn19sl fpc_shortstr_to_shortstr
1.7% ppn19sl SYSTEM_SYSFREEMEM$POINTER$$LONGWORD
1.5% ppn19sl CCLASSES_TLINKEDLIST_$__CLEAR

After r14137:
6.4% ppn19sl SYSTEM_SYSGETMEM_FIXED$LONGWORD$$POINTER 4.9% ppn19sl AGGAS_TGNUASSEMBLER_$__WRITETREE$TASMLIST 3.3% libSystem.B.dylib __bzero
2.7% ppn19sl CCLASSES_TFPHASHLIST_$__INTERNALFIND$LONGWORD$SHORTSTRING$LONGINT$$LONGINT 2.6% ppn19sl SYSTEM_TOBJECT_$__CLEANUPINSTANCE
2.3% libSystem.B.dylib __memcpy
2.0% ppn19sl SYSTEM_SYSFREEMEM_FIXED$PFREELISTS$PMEMCHUNK_FIXED$$LONGWORD 1.9% ppn19sl fpc_shortstr_to_shortstr
1.7% ppn19sl CCLASSES_TLINKEDLIST_$__CLEAR
1.6% ppn19sl SYSTEM_SYSFREEMEM$POINTER$$LONGWORD

The only thing that changed in r14137 was adding a prefetch statement to tgnuassembler.writetree (on i386 you have to compile with -Cppentium4 or higher for the prefetch statement to do anything though). As you can see, the total number of samples in that function was reduced by 1.2% (and they no longer mostly occurred right after the instruction that loads the assembler instruction type field of the new instruction for the huge case statement).

I've tried to optimize sysgetmem_fixed also with some prefetch statements (the above already includes those, because even though I only committed them in r14197, I had them locally applied already since quite a while) but it still takes up quite a bit of time. Adding prefetches there also didn't help that much; they helped more in freemem (I believe it went from 3-4% to its current 1.6-1.7%).

Jonas

Paul Ishenin wrote

I have attached compiler gprof output of compiler itself. Using output I was able to find and improve(?) 3 functions I found in output.

Did you benchmark whether this changed code is indeed faster and whether it makes any difference at all for the compiler? Changing working code because it /might/ become slightly faster that way is not a good approach to keeping source code either maintainable or fast (especially not if it's done by adding more with-statements).

Jonas

I did not benchmarked the changed code. I made the change because of gprof numbers (compiler compiles the compiler):

% cumulative self self total
time seconds seconds calls Ts/call Ts/call name before:
0.62 4.27 0.05
CCLASSES_TDYNAMICARRAY_$__WRITE$formal$LONGWORD
after:
0.37 4.99 0.03
CCLASSES_TDYNAMICARRAY_$__WRITE$formal$LONGWORD

On a smaller test (compiling not the compiler but some small application) dynamicarray.read and write were on top of the list.

Best regards,
Paul Ishenin.

Rewriting code and guessing that the result will probably be faster is seldom a good idea on modern processors.

Jonas

The only thing that changed in r14137 was adding a prefetch statement to tgnuassembler.writetree (on i386 you have to compile with -Cppentium4 or higher for the prefetch statement to do anything though).

Actually pentium3 ;)