Author Topic: As build log gets longer compilation gets slower (addressed in SVN 9852)  (Read 13946 times)

Offline headkase

  • Almost regular
  • **
  • Posts: 159
Edit: SVN 9852 is now available with the change log indicating it addresses this issue. (Link).

I have successfully compiled the current SVN (9851) with This toolchain.  That is a full compile of WxWidgets 2.8.12 Unicode (needed -fpermissive in CXXFLAGS), BOOST 1.55, SVN 9851, and the complete contrib plugins (including Nassi which needed BOOST).  While getting everything figured out I compiled 9851 with 9851 a few times over so it can be assured that the output is correctly handling complex projects.  There are an excessive amount of warnings during the compile process but no actual errors and as said the output works correctly.  With the main Code::Blocks project the compilation starts fast but then begins to slow as the build log gets longer, the contrib plugins however eventually generate so many warnings that the build log grows to tens of thousands of lines and compilation slows to a crawl.  I aborted compilation after 172 minutes for contrib and it was still nowhere near done.  Disabling compiler logging and enabling the "-w" compiler flag to suppress warnings the contrib plugins successfully compile in a few minutes instead of hours and not done.  As the build log grows longer performance suffers.
« Last Edit: July 30, 2014, 04:46:06 am by headkase »

Offline Alpha

  • Developer
  • Lives here!
  • *****
  • Posts: 1513
Re: As build log gets longer compilation gets slower
« Reply #1 on: July 23, 2014, 01:36:03 am »
I believe each append to the build log messages is immediately followed with an auto-resize of columns.  This is a likely performance candidate.  (Apologies, I am unable to explore further into it at the moment.)

Offline headkase

  • Almost regular
  • **
  • Posts: 159
Re: As build log gets longer compilation gets slower
« Reply #2 on: July 23, 2014, 01:44:43 am »
I'm always more than willing to pull a new SVN to test for you.. ;)

The vast majority of the warnings are related to WxWidgets.  It seems everything needs to reference that.

Offline Alpha

  • Developer
  • Lives here!
  • *****
  • Posts: 1513
Re: As build log gets longer compilation gets slower
« Reply #3 on: July 24, 2014, 02:30:40 am »
Could you test if this patch reduces the performance issues:
Code
diff --git a/src/plugins/compilergcc/compilergcc.cpp b/src/plugins/compilergcc/compilergcc.cpp
index 3e82e3b..f6744c6 100644
--- a/src/plugins/compilergcc/compilergcc.cpp
+++ b/src/plugins/compilergcc/compilergcc.cpp
@@ -3467,7 +3467,14 @@ void CompilerGCC::LogWarningOrError(CompilerLineType lt, cbProject* prj, const w
     Logger::level lv = (lt == cltError)   ? Logger::error
                      : (lt == cltWarning) ? Logger::warning : Logger::info;
 
-    m_pListLog->Append(errors, lv, 2);
+    static wxDateTime lastAutofitTime = wxDefaultDateTime;
+    if ( lastAutofitTime < (wxDateTime::Now() - wxTimeSpan::Seconds(3)) )
+    {
+        m_pListLog->Append(errors, lv, 2);
+        lastAutofitTime = wxDateTime::Now();
+    }
+    else
+        m_pListLog->Append(errors, lv);
 
     // add to error keeping struct
     m_Errors.AddError(lt, prj, filename, line.IsEmpty() ? 0 : atoi(wxSafeConvertWX2MB(line)), msg);

Offline headkase

  • Almost regular
  • **
  • Posts: 159
Re: As build log gets longer compilation gets slower
« Reply #4 on: July 24, 2014, 04:33:59 am »
Ok, took a bit to run the process a few times but here are the results.

Processor: Intel Core i5 4670 quad-core @ 3.4GHz.  Build Options: Number of processes for parallel builds set to 4 for all runs.

All runs use the SVN 9851.

--

Without patch compile SVN 9851 with patched source.  No logging, with "-w" to suppress warnings.

Code::Blocks -> 1 min 38 sec.
Contrib Plugins Workspace -> 4 min 23 sec.

--

With patched SVN 9851 compile compiling patched source.  Compiler logging "Full Command Line", warnings set to default show.

Code::Blocks -> 1 min 49 sec.  0 errors, 770 warnings.
Contrib Plugins Workspace -> 28 min, 11 sec.  0 errors, 11812 warnings.

--

So, the patch has significantly improved the compile process.  Down to 28 minutes done what went for 3 hours and still not done.  The unpatched warnings pause on every warning as well, patched they just fly by.
« Last Edit: July 24, 2014, 04:37:38 am by headkase »

Offline headkase

  • Almost regular
  • **
  • Posts: 159
Re: As build log gets longer compilation gets slower
« Reply #5 on: July 24, 2014, 04:54:48 am »
And here is some sample output for what is generating the warnings.  None of the compilation fails (errors) just lots of warnings and the output works fine:

Code
E:\Data\MinGW\CB\wxMSW-2.8.12\include/wx/dynarray.h:877:5: note: in expansion of macro 'WX_DEFINE_TYPEARRAY_WITH_DECL_PTR'
     WX_DEFINE_TYPEARRAY_WITH_DECL_PTR(T, name, wxBaseArrayDouble, wxARRAY_EMPTY expmode)
     ^
E:\Data\MinGW\CB\wxMSW-2.8.12\include/wx/dynarray.h:995:1: note: in expansion of macro 'WX_DEFINE_USER_EXPORTED_ARRAY_DOUBLE'
 WX_DEFINE_USER_EXPORTED_ARRAY_DOUBLE(double, wxArrayDouble, class WXDLLIMPEXP_BASE);
 ^
E:\Data\MinGW\CB\wxMSW-2.8.12\include/wx/dynarray.h: In member function 'void wxArrayLong::Remove(_wxArraywxArrayLong)':
E:\Data\MinGW\CB\wxMSW-2.8.12\include/wx/debug.h:194:43: warning: typedef 'wxDummyCheckInt' locally defined but not used [-Wunused-local-typedefs]
     #define wxFORCE_SEMICOLON typedef int wxDummyCheckInt
                                           ^
E:\Data\MinGW\CB\wxMSW-2.8.12\include/wx/debug.h:224:9: note: in expansion of macro 'wxFORCE_SEMICOLON'
         wxFORCE_SEMICOLON /* just to force a semicolon */
         ^
E:\Data\MinGW\CB\wxMSW-2.8.12\include/wx/dynarray.h:353:7: note: in expansion of macro 'wxCHECK2_MSG'
       wxCHECK2_MSG( iIndex != wxNOT_FOUND, return,                    \
       ^
E:\Data\MinGW\CB\wxMSW-2.8.12\include/wx/dynarray.h:486:5: note: in expansion of macro '_WX_DEFINE_TYPEARRAY_HELPER'
     _WX_DEFINE_TYPEARRAY_HELPER(T, name, base, classexp, _WX_PTROP_NONE)
     ^

Offline Alpha

  • Developer
  • Lives here!
  • *****
  • Posts: 1513
Re: As build log gets longer compilation gets slower
« Reply #6 on: July 25, 2014, 02:06:21 am »
Thanks for detailed testing.  My guess is that the largest remaining slowdown is that C::B matches every line of output against multiple regexes.  To improve that, we probably would have to try integrating a faster implementation (if one exists).  The library re2 claims to do that, but I have not tested.  However, I am not sure if it is worth the effort to integrate.  A compiler spitting out thousands of warnings generally means you have bigger problems...
I recall reading somewhere that piped processes in wxWidgets are slow to handle large volumes of text, so that might also be related.

By the way, when using wx28 (they fixed it in wx30, but apparently did not backport) with gcc4.8+, I usually add -Wno-unused-local-typedefs to global options, so that other warnings are not drowned out.  Possibly including wx headers with the -isystem flag would help as well (untested).

Offline headkase

  • Almost regular
  • **
  • Posts: 159
Re: As build log gets longer compilation gets slower
« Reply #7 on: July 25, 2014, 02:32:41 am »
Thank you for looking into it so far. :)

Almost every single warning is a "note" about the expansion of a macro.  Whenever anything seems to reference Wx that is what gets spit out.  That is the majority.  When I'm compiling my own, albeit very simple, programs no warnings occur.  I could recompile Wx itself, if that is what you mean, with which flags?  (The CXXFLAGS = part).

Getting 11000+ warnings I would assume wouldn't happen in normal usage, now although it has been seen to affect compile times as each warning eventually consumes around a second of real time just to display.  That is an edge case and is only up to you to decide if it is worth pursuing.  Thanks again though, if you'd like me to do anything else then just ask - I'm up for it! ;)

Offline ollydbg

  • Developer
  • Lives here!
  • *****
  • Posts: 5913
  • OpenCV and Robotics
    • Chinese OpenCV forum moderator
Re: As build log gets longer compilation gets slower
« Reply #8 on: July 25, 2014, 03:57:33 am »
Thanks for detailed testing.  My guess is that the largest remaining slowdown is that C::B matches every line of output against multiple regexes.  To improve that, we probably would have to try integrating a faster implementation (if one exists).  The library re2 claims to do that, but I have not tested.  However, I am not sure if it is worth the effort to integrate.  ....

Maybe off topic, I once tried a similar package re2c, which need to first write a grammar file, and generate a C source file. I use it for a lexer, it runs much faster then flex. BTW: Quex is also fast.
If some piece of memory should be reused, turn them to variables (or const variables).
If some piece of operations should be reused, turn them to functions.
If they happened together, then turn them to classes.

Offline headkase

  • Almost regular
  • **
  • Posts: 159
Re: As build log gets longer compilation gets slower
« Reply #9 on: July 25, 2014, 05:25:58 am »
Please take this topic wherever it needs to go! ;)

Just to fill out what I did, I followed the: Wiki to compile Code::Blocks from source.  I deviated from that while compiling WxWidgets: I had to add "-fpermissive" to the CXXFLAGS for GCC 4.9.1 to not bork on it.  Boost I did the bootstrap and b2 separately than what the Wiki describes.  I'm not using WxWidgets myself and the only time those warnings appear is when compiling Code::Blocks itself or the Contrib Workspace.  This self compiled version, as I have said, works fine to the best I understand it.  It successfully compiles itself again so all those warnings do not seem to be impeding its functionality.

The "notes" for macro expansions might be intrinsic to GCC 4.9.1 itself, I'm not an expert but I think Code::Blocks would have failed spectacularly by now if the warnings amounted to structural issues.

Offline headkase

  • Almost regular
  • **
  • Posts: 159
Re: As build log gets longer compilation gets slower
« Reply #10 on: July 25, 2014, 08:53:32 am »
Googling around I've found here and there (like here) that all these "note" warnings are to be expected with WxWidgets 2.8.x and newer compilers.  I don't know when the behavior changed.

So, I compiled Code::Blocks against WxWidgets 3.0.1 and during the compilation process there was only expected output, not the flood of warnings given with 2.8.x.  Unfortunately the resulting binary linked against 3.0.1 crashes on startup for myself.

So, all those warnings: expected behavior.

Here is my self-compiled Code::Blocks (just IDE, no compiler) if you'd like to punish it yourself.
(This is straight SVN, doesn't have the patch given in this thread applied.)

Edit: And also, when compiling WxWidgets 2.8.x on a bare command line all those warnings go by too - before it even gets into the IDE.
« Last Edit: July 25, 2014, 10:19:35 am by headkase »

Offline Jenna

  • Administrator
  • Lives here!
  • *****
  • Posts: 7255
Re: As build log gets longer compilation gets slower
« Reply #11 on: July 25, 2014, 12:16:25 pm »
If you add "-Wno-unused-local-typedefs" to the global variable "cb_release_type" ("Settings -> Global variables") most of the warnings go away.

Offline headkase

  • Almost regular
  • **
  • Posts: 159
Re: As build log gets longer compilation gets slower
« Reply #12 on: July 25, 2014, 12:29:46 pm »
Apparently my reading comprehension could use some work too as Alpha above you said much the same.  Thank you! ;)

Offline headkase

  • Almost regular
  • **
  • Posts: 159
Re: As build log gets longer compilation gets slower
« Reply #13 on: July 30, 2014, 04:03:50 am »
See that the change log for 9852 addresses this issue.  Thank you.

Offline oBFusCATed

  • Developer
  • Lives here!
  • *****
  • Posts: 13413
    • Travis build status
Crash report in the IRC channel...

Quote
(2014-07-30 00:38:32) muumi: Hello. Current (trunk #9852) Codeblocks crashes on first compile in Ubuntu 14.04/XFCE/wx3.0 after launch. Please see http://dpaste.com/1BNNQZ5 for valgrind log and crashdump.
(2014-07-30 00:41:57) obfuscated: can you try if rev9851 works correctly?
(2014-07-30 00:43:05) obfuscated: if it works please post in this topic: http://forums.codeblocks.org/index.php/topic,19482.0.html
(2014-07-30 00:50:11) muumi: Revision 9851 does not crash.
(2014-07-30 01:20:01) muumi: The crash can be fixed by this patch: http://dpaste.com/0FYECQP
(2014-07-30 01:21:18) muumi: I don't know, why the wxDefaultDateTime is not valid, is there a race condition or what?
(most of the time I ignore long posts)
[strangers don't send me private messages, I'll ignore them; post a topic in the forum, but first read the rules!]