Code::Blocks Forums

Developer forums (C::B DEVELOPMENT STRICTLY!) => Plugins development => Topic started by: rickg22 on November 23, 2005, 08:43:23 am

Title: Optimizing Makefilegenerator
Post by: rickg22 on November 23, 2005, 08:43:23 am
After seeing how long large projects take to calculate the compilation commands, i realized that the string replacing is EXTREMELY SUBOPTIMAL.

    compilerCmd.Replace(_T("$compiler"), compilerStr);
    compilerCmd.Replace(_T("$linker"), m_CompilerSet->GetPrograms().LD);
    compilerCmd.Replace(_T("$lib_linker"), m_CompilerSet->GetPrograms().LIB);
    compilerCmd.Replace(_T("$rescomp"), m_CompilerSet->GetPrograms().WINDRES);

etc.

My proposal is to use wxStringTokenizer to search for the macros (using '$' as token), and do the replacing manually using the Matches() function. This will allow us to speed up the generation time by around 15x.

Objections? Comments?
Title: Re: Optimizing Makefilegenerator
Post by: mandrav on November 23, 2005, 09:14:16 am
It's not replace that slows down this process. It's the calls to wxFileName::Normalize. For each file and for each build target, filenames are recalculated. We have lowered this overhead a lot by caching the calculated filenames and recalculating them when needed.
It will be optimized even more with the optimizations Thomas will do to project loading.

And all these are only noticeable in *large* projects like C::B itself...
Title: Re: Optimizing Makefilegenerator
Post by: rickg22 on November 23, 2005, 05:08:52 pm
Awww... and *just* when I came up with the idea of a cacheable search-and-replace class... :(  :lol:

Anyway, how did you find out the normalizing was the most time-consuming part?
Do you happen to have a profiler report? (I'd love to see it)
Can anybody help us with the profiling?
Title: Re: Optimizing Makefilegenerator
Post by: rickg22 on November 23, 2005, 05:38:35 pm
Hey wait a minute!

I just noticed something VERY SUSPICIOUS.

Code
lines 224 and following:
    if (target &&
        target->GetParentProject()->GetModeForPCH() == pchObjectDir)
    {
        wxArrayString includedDirs; // avoid adding duplicate dirs...
        wxString sep = wxFILE_SEP_PATH;
        // find all PCH in project
        int count = target->GetParentProject()->GetFilesCount();
        for (int i = 0; i < count; ++i)
        {

Does this loop get executed EVERYTIME CreateSingleFileCompileCmd is invoked? :shock: That adds QUADRATIC complexity! :shock:

Oh wait, nevermind, that option is not executed in my setup.... darn, I really need profiler info...
Title: Re: Optimizing Makefilegenerator
Post by: mandrav on November 23, 2005, 05:52:24 pm
MakefileGenerator is used as a quick hack to generate the build command line. It will need to be rewritten anyway as it doesn't support many of the newest features.
I will implement another optimized command-line generator for builds.
It won't take long...
Title: Re: Optimizing Makefilegenerator
Post by: Ceniza on November 23, 2005, 06:14:54 pm
Quote from: mandrav
I will implement another optimized command-line generator for builds.

Psssst, any possibility to add the so wanted (at least for me) multithreaded build (a.k.a. make -j# clone)?

Maybe that way it could't take you a bit longer :wink:
Title: Re: Optimizing Makefilegenerator
Post by: mandrav on November 23, 2005, 07:02:58 pm
Quote from: mandrav
I will implement another optimized command-line generator for builds.

Psssst, any possibility to add the so wanted (at least for me) multithreaded build (a.k.a. make -j# clone)?

Maybe that way it could't take you a bit longer :wink:

The problem with that is that wxExecute can't be used inside any thread other than the main...
Title: Re: Optimizing Makefilegenerator
Post by: Ceniza on November 23, 2005, 07:24:06 pm
So it should be made in the main thread... evil.

I'll play a bit with it and see what I find.
Title: Re: Optimizing Makefilegenerator
Post by: Urxae on November 23, 2005, 07:57:48 pm
Psssst, any possibility to add the so wanted (at least for me) multithreaded build (a.k.a. make -j# clone)?

Maybe that way it could't take you a bit longer :wink:

The problem with that is that wxExecute can't be used inside any thread other than the main...

But you can still have it be called asynchronously, right? So maybe you could use some mechanism (events?) to tell the main thread to call wxExecute, which can then be activated from other threads?
Title: Re: Optimizing Makefilegenerator
Post by: rickg22 on November 23, 2005, 08:18:42 pm
I will implement another optimized command-line generator for builds.
It won't take long...

I want to help I want to help I want to help! :o
Title: Re: Optimizing Makefilegenerator
Post by: Ceniza on November 23, 2005, 08:19:38 pm
Quote from: Urxae
But you can still have it be called asynchronously, right? So maybe you could use some mechanism (events?) to tell the main thread to call wxExecute, which can then be activated from other threads?

That'd be the hacky idea: You! Yes, you! The one able to call wxExecute! Call it with these parameters for me! Now!

The function could also try to handle it all avoiding the use of threads.
Title: Re: Optimizing Makefilegenerator
Post by: thomas on November 23, 2005, 08:25:02 pm
It is actually pretty easy to call several compiler instances asynchronously. But it is an awful mess to sort out the compiler's output from several running processes.
Title: Re: Optimizing Makefilegenerator
Post by: mandrav on November 23, 2005, 08:32:16 pm
I never said it isn't possible ;)
It's just that the last time this subject was brought up, the usage of the thread pool was discussed.

Anyway, this is deliberately not being currently worked on because the compiler will be redesigned so...
Title: FIRST RESULTS
Post by: rickg22 on November 24, 2005, 07:01:03 am
I added 15 timers using wxStopwatch (they're static variables, they're reset to 0 when compilation starts). Here are the results:

Code
SDK Only
----------

Timer  1: 0 ms
Timer  2: 5046 ms
Timer  3: 1312 ms
Timer  4: 0 ms
Timer  5: 1189 ms
Timer  6: 0 ms
Timer  7: 3142 ms
Timer  8: 15 ms
Timer  9: 0 ms
Timer 10: 1577 ms
Timer 11: 16 ms
Timer 12: 0 ms
Timer 13: 218 ms
Timer 14: 48 ms
Timer 15: 0 ms

All Targets
---------------
Timer  1: 0 ms
Timer  2: 17007 ms
Timer  3: 3243 ms
Timer  4: 0 ms
Timer  5: 3733 ms
Timer  6: 16 ms
Timer  7: 10747 ms
Timer  8: 78 ms
Timer  9: 0 ms
Timer 10: 5030 ms
Timer 11: 32 ms
Timer 12: 0 ms
Timer 13: 894 ms
Timer 14: 110 ms
Timer 15: 0 ms

These times reflect the calculation of the compiling commands ONLY. The actual compilation times are not taken into account. The compilation method was a full rebuild.

And now, the (shameful? :lol: ) modified source code of the routine in question:

Code
wxString MakefileGenerator::CreateSingleFileCompileCmd(const wxString& command,
                                                        ProjectBuildTarget* target,
                                                        ProjectFile* pf,
                                                        const wxString& file,
                                                        const wxString& object,
                                                        const wxString& deps)
{
    // in case of linking command, deps has resource objects
    UpdateCompiler(target);
    wxStopWatch sw;
    wxString compilerStr;
    if (pf)
    {
        if (pf->compilerVar.Matches(_T("CPP")))
            compilerStr = m_CompilerSet->GetPrograms().CPP;
        else if (pf->compilerVar.Matches(_T("CC")))
            compilerStr = m_CompilerSet->GetPrograms().C;
        else if (pf->compilerVar.Matches(_T("WINDRES")))
            compilerStr = m_CompilerSet->GetPrograms().WINDRES;
        else
            return wxEmptyString; // unknown compiler var
    }
    else
    {
    wxFileName fname(file);
    if (fname.GetExt().Lower().Matches(_T("c")))
            compilerStr = m_CompilerSet->GetPrograms().C;
        else
            compilerStr = m_CompilerSet->GetPrograms().CPP;
    }
    time1 += sw.Time();
    sw.Start();
    wxString cflags;
    wxString global_cflags;
wxString prj_cflags;
DoAppendCompilerOptions(global_cflags, 0L, true);
DoAppendCompilerOptions(prj_cflags, 0L);
    DoGetMakefileCFlags(cflags, target);
    time2 += sw.Time();
    sw.Start();

    if (target)
    {
        cflags.Replace(_T("$(") + target->GetTitle() + _T("_GLOBAL_CFLAGS)"), global_cflags);
        cflags.Replace(_T("$(") + target->GetTitle() + _T("_PROJECT_CFLAGS)"), prj_cflags);
    }
    else if (!target && !pf) // probably single file compilation
        cflags = global_cflags;

    wxString ldflags;
wxString global_ldflags;
wxString prj_ldflags;
DoAppendLinkerOptions(global_ldflags, 0L, true);
DoAppendLinkerOptions(prj_ldflags, 0L);
DoGetMakefileLDFlags(ldflags, target);
    time3 += sw.Time();
    sw.Start();
    if (target)
    {
        ldflags.Replace(_T("$(") + target->GetTitle() + _T("_GLOBAL_LDFLAGS)"), global_ldflags);
        ldflags.Replace(_T("$(") + target->GetTitle() + _T("_PROJECT_LDFLAGS)"), prj_ldflags);
    }
    else if (!target && !pf) // probably single file compilation
        ldflags = global_ldflags;

    time4 += sw.Time();
    sw.Start();
    wxString ldadd;
wxString global_ldadd;
wxString prj_ldadd;
DoAppendLinkerLibs(global_ldadd, 0L, true);
DoAppendLinkerLibs(prj_ldadd, 0L);
DoGetMakefileLibs(ldadd, target);
    time5 += sw.Time();
    sw.Start();
    if (target)
    {
        ldadd.Replace(_T("$(") + target->GetTitle() + _T("_GLOBAL_LIBS)"), global_ldadd);
        ldadd.Replace(_T("$(") + target->GetTitle() + _T("_PROJECT_LIBS)"), prj_ldadd);
    }
    else if (!target && !pf) // probably single file compilation
        ldadd = global_ldadd;

    time6 += sw.Time();
    sw.Start();
wxString global_res_incs;
wxString prj_res_incs;
wxString res_incs;
DoAppendResourceIncludeDirs(global_res_incs, 0L, m_CompilerSet->GetSwitches().includeDirs, true);
DoAppendResourceIncludeDirs(prj_res_incs, 0L, m_CompilerSet->GetSwitches().includeDirs);
res_incs << global_res_incs << _T(" ") << prj_res_incs << _T(" ");
DoAppendResourceIncludeDirs(res_incs, target, m_CompilerSet->GetSwitches().includeDirs);

    wxString incs;
wxString global_incs;
wxString prj_incs;
DoAppendIncludeDirs(global_incs, 0L, m_CompilerSet->GetSwitches().includeDirs, true);
DoAppendIncludeDirs(prj_incs, 0L, m_CompilerSet->GetSwitches().includeDirs);
DoGetMakefileIncludes(incs, target);

    time7 += sw.Time();
    sw.Start();
    if (target)
    {
        incs.Replace(_T("$(") + target->GetTitle() + _T("_GLOBAL_INCS)"), global_incs);
        incs.Replace(_T("$(") + target->GetTitle() + _T("_PROJECT_INCS)"), prj_incs);
    }
    else if (!target && !pf) // probably single file compilation
        incs = global_incs;

    // for PCH to work, the very first include dir *must* be the object output dir
    // *only* if PCH is generated in the object output dir
    time8 += sw.Time();
    sw.Start();
    if (target &&
        target->GetParentProject()->GetModeForPCH() == pchObjectDir)
    {
        wxArrayString includedDirs; // avoid adding duplicate dirs...
        wxString sep = wxFILE_SEP_PATH;
        // find all PCH in project
        int count = target->GetParentProject()->GetFilesCount();
        for (int i = 0; i < count; ++i)
        {
            ProjectFile* f = target->GetParentProject()->GetFile(i);
            if (FileTypeOf(f->relativeFilename) == ftHeader &&
                f->compile)
            {
                // it is a PCH; add it's object dir to includes
                wxString dir = wxFileName(target->GetObjectOutput() + sep + f->GetObjName()).GetPath();
                if (includedDirs.Index(dir) == wxNOT_FOUND)
                {
                    includedDirs.Add(dir);
                    incs = m_CompilerSet->GetSwitches().includeDirs +
                            dir +
                            _T(" ") +
                            incs;
                }
            }
        }
    }

    time9 += sw.Time();
    sw.Start();
    wxString libs;
wxString global_libs;
wxString prj_libs;
DoAppendLibDirs(global_libs, 0L, m_CompilerSet->GetSwitches().libDirs, true);
DoAppendLibDirs(prj_libs, 0L, m_CompilerSet->GetSwitches().libDirs);
DoGetMakefileLibDirs(libs, target);

    time10 += sw.Time();
    sw.Start();
    if (target)
    {
        libs.Replace(_T("$(") + target->GetTitle() + _T("_GLOBAL_LIBDIRS)"), global_libs);
        libs.Replace(_T("$(") + target->GetTitle() + _T("_PROJECT_LIBDIRS)"), prj_libs);
    }
    else if (!target && !pf) // probably single file compilation
        libs = global_libs;

    time11 += sw.Time();
    sw.Start();

    wxString output;
    if (target)
        output = UnixFilename(target->GetOutputFilename());
    else
    {
        wxString object_unquoted(object);
        if (!object_unquoted.IsEmpty() && object_unquoted.GetChar(0) == '"')
            object_unquoted.Replace(_T("\""), _T(""));
        wxFileName fname(object_unquoted);
        fname.SetExt(EXECUTABLE_EXT);
        output = fname.GetFullPath();
    }

    time12 += sw.Time();
    sw.Start();

    Manager::Get()->GetMacrosManager()->ReplaceEnvVars(output);
    ConvertToMakefileFriendly(output);
    QuoteStringIfNeeded(output);

    wxString linkobjs;

    time13 += sw.Time();
    sw.Start();

    wxString compilerCmd = command;
    compilerCmd.Replace(_T("$compiler"), compilerStr);
    compilerCmd.Replace(_T("$linker"), m_CompilerSet->GetPrograms().LD);
    compilerCmd.Replace(_T("$lib_linker"), m_CompilerSet->GetPrograms().LIB);
    compilerCmd.Replace(_T("$rescomp"), m_CompilerSet->GetPrograms().WINDRES);
    compilerCmd.Replace(_T("$options"), cflags);
    compilerCmd.Replace(_T("$link_options"), ldflags);
    compilerCmd.Replace(_T("$includes"), incs);
    compilerCmd.Replace(_T("$res_includes"), res_incs);
    compilerCmd.Replace(_T("$libdirs"), libs);
    compilerCmd.Replace(_T("$libs"), ldadd);
    compilerCmd.Replace(_T("$file"), file);
    compilerCmd.Replace(_T("$dep_object"), deps);
    compilerCmd.Replace(_T("$object"), object);
    compilerCmd.Replace(_T("$exe_output"), output);
    compilerCmd.Replace(_T("$resource_output"), object);
    compilerCmd.Replace(_T("$link_resobjects"), deps);
    compilerCmd.Replace(_T("$link_objects"), object);
    // the following were added to support the QUICK HACK
    // at directcommands.cpp:576
    compilerCmd.Replace(_T("$+link_objects"), object);
    compilerCmd.Replace(_T("$-link_objects"), object);
    compilerCmd.Replace(_T("$-+link_objects"), object);
    compilerCmd.Replace(_T("$+-link_objects"), object);

    time14 += sw.Time();
    sw.Start();

    if (target && (target->GetTargetType() == ttStaticLib || target->GetTargetType() == ttDynamicLib))
    {
        wxFileName fname(target->GetOutputFilename());
        if (!fname.GetName().StartsWith(m_CompilerSet->GetSwitches().libPrefix))
            fname.SetName(m_CompilerSet->GetSwitches().libPrefix + fname.GetName());
        fname.SetExt(m_CompilerSet->GetSwitches().libExtension);
        wxString out = UnixFilename(fname.GetFullPath());
        ConvertToMakefileFriendly(out);
        QuoteStringIfNeeded(out);
        if (target->GetTargetType() == ttStaticLib || target->GetCreateStaticLib())
            compilerCmd.Replace(_T("$static_output"), out);
        else
        {
            compilerCmd.Replace(_T("-Wl,--out-implib=$static_output"), _T("")); // special gcc case
            compilerCmd.Replace(_T("$static_output"), _T(""));
        }
        if (target->GetCreateDefFile())
        {
            fname.SetExt(_T("def"));
            out = UnixFilename(fname.GetFullPath());
            ConvertToMakefileFriendly(out);
            QuoteStringIfNeeded(out);
            compilerCmd.Replace(_T("$def_output"), out);
        }
        else
        {
            compilerCmd.Replace(_T("-Wl,--output-def=$def_output"), _T("")); // special gcc case
            compilerCmd.Replace(_T("$def_output"), _T(""));
        }
    }

    time15 += sw.Time();

#ifndef __WXMSW__
    // run the command in a shell, so backtick'd expressions can be evaluated
    compilerCmd = m_Compiler->GetConsoleShell() + _T(" '") + compilerCmd + _T("'");
#endif
    return compilerCmd;
}


I hope these timings help us determine which takes longer and why.
Title: Re: Optimizing Makefilegenerator
Post by: mandrav on November 24, 2005, 09:12:35 am
I 'm sure there is something wrong with the numbers you posted:

Quote
Timer  2: 5046 ms

5 seconds for this?

Quote
Code
    sw.Start();
    wxString cflags;
    wxString global_cflags;
wxString prj_cflags;
DoAppendCompilerOptions(global_cflags, 0L, true);
DoAppendCompilerOptions(prj_cflags, 0L);
    DoGetMakefileCFlags(cflags, target);
    time2 += sw.Time();

And you mean to tell me that you 're waiting 40+ seconds only for commands generation when building the project?
What is your PC's specs?
Have you disabled this safe_but_slow tweak of yours?
Title: Re: Optimizing Makefilegenerator
Post by: Urxae on November 24, 2005, 12:00:09 pm
Well, DoAppendCompilerOptions does call MacrosManager::ReplaceEnvVars, which calls MacrosManager::ReplaceMacros, which looks like it might take a lot of time. String operations tend to be more expensive that one would think.
That, and we don't yet know his system specs of course.
Title: Re: Optimizing Makefilegenerator
Post by: mandrav on November 24, 2005, 01:11:53 pm
Still...
40+ seconds?!?  :shock:
Title: Re: Optimizing Makefilegenerator
Post by: Urxae on November 24, 2005, 02:41:58 pm
Well, I have noticed on my computer (750 MHz laptop, 256 MB RAM) that it can take quite some time before C::B starts the first g++ when compiling itself. I'm not sure if it differs if more files need recompiling, and I don't feel like trying: a full rebuild usually takes around an hour on this machine.
Yes I know, I need a better machine :(.
Title: Re: Optimizing Makefilegenerator
Post by: rickg22 on November 24, 2005, 05:24:51 pm
Yiannis:

I got an old Athlon 1800+ running at 1.5 GHz. My machine isn't very fast. And YES, I *did* disable the stability tweak.

Second: The measurement used by wxStopWatch isn't very accurate. This, and taking into account that the times are
calculated in VERY TIGHT loops and then added. CPUs don't use subatomic clocks for
time measurement, and noticing that each call to this routine may take about 10ms, i'm sure there are cumulative rounding errors.
(The full-rebuild version takes about 10 seconds to calculate, and the SDK test takes about 5 seconds. So I'd say the reported times are 4X the real time ellapsed.)

However, we should pay attention to the RELATIVE times. So call them milliseconds, or clock ticks, the point is that some parts of the routine take much longer than they should.
Remember you told me that the string replacing parts weren't very CPU-consuming? Well, the reported time was less than 5% the total times for the calculation.

Also take into account the percentages. The numbers for the SDK calculation are proportional to the numbers for the full-rebuild calculation. So the numbers do make sense.

Edit: here they are, the normalized times.
Code
Timer  1: 0
Timer  2: 5046 ms (40.16%)
Timer  3: 1312 ms (10.44%)
Timer  4: 0 ms
Timer  5: 1189 ms (9.46%)
Timer  6: 0 ms
Timer  7: 3142 ms (25.01%)
Timer  8: 15 ms   (0.12%)
Timer  9: 0 ms
Timer 10: 1577 ms (12.55%)
Timer 11: 16 ms   (0.13%)
Timer 12: 0 ms
Timer 13: 218 ms  (1.73%)
Timer 14: 48 ms   (0.38%)
Timer 15: 0 ms

Total "time": 12563

All Targets
---------------
Timer  1: 0 ms
Timer  2: 17007 ms (41.61%)
Timer  3: 3243 ms  (7.93%)
Timer  4: 0 ms
Timer  5: 3733 ms  (9.13%)
Timer  6: 16 ms    (0.04%)
Timer  7: 10747 ms (26.29%)
Timer  8: 78 ms    (0.19%)
Timer  9: 0 ms
Timer 10: 5030 ms  (12.30%)
Timer 11: 32 ms    (0.08%)
Timer 12: 0 ms
Timer 13: 894 ms   (2.19%)
Timer 14: 110 ms   (0.27%)
Timer 15: 0 ms

Total "time": 40874

So, for both cases, timer2 gets 41%, timer7 gets 25% and timer10 gets 12%.

Now, how are we gonna solve this?
We could, for example, move some of the calculations to outside the loop (that calls the function in question), because they're dependent on the target, not on the filename. I'd appreciate if you gave more details on what strings exactly you're generating. All those replaced macros get me dizzy.
Title: Re: Optimizing Makefilegenerator
Post by: rickg22 on November 25, 2005, 08:13:20 am
Good news people! Yiannis sent me a prototype for an optimized version, and it's got rid of almost all of the bottleneck!

I measured the full-rebuild calculation times, with and without patch.

Without patch: 19.16 seconds (with manual stopwatch)
With patch: 01.80 seconds  (with manual stopwatch). This varies on occasions, up to 4 seconds. I'm not sure why.

Now we have only to take care of some minor details and a linking bug, and we're done :)
Title: Re: Optimizing Makefilegenerator
Post by: Ceniza on November 25, 2005, 08:51:13 am
Sounds good :)
Title: Re: Optimizing Makefilegenerator
Post by: rickg22 on November 28, 2005, 07:05:58 am
More good news, people! I fully revamped the MacrosManager, and this alone reduced the full rebuild calculation time from 13 seconds to 1.7! :shock:

For those curious, makefile generation is now practically *instant*. Takess less than a second now!

(Yes, I rebuilt codeblocks, compared makefile generation and everything works exactly the same. Ceniza compared, too!)

I can't wait till Yiannis uploads his part of the patch :D