Menu ▾ ▴

Latest cppcheck versions *very* much slower than before

General Discussion
Neil Bird
2018-07-11
2019-11-10

  • Neil Bird

    Neil Bird - 2018-07-11

    I've had a look through the issues, and can't see anything recent that pertains; I've currently got 1.80 rolled out and was running 1.83 to see what the changes were. Normally cppcheck doesn't take terribly long across our codebase, but I started 1.83 yesterday afternoon and it was still only halfway done this morning!

    A verbose/progress run show the following sort of output:

    Checking trunk/path/to/file.cpp ...
Defines: CPPCHECK=1;PROJECT=Framework;_WIN32=1;WIN32=1;_MSC_VER=1400;_M_IX86=1;_DEBUG=1;XP_WIN=1
Includes: -Itrunk/include/ -I/usr/include/qt5/
Platform:win32A
Checking trunk/path/to/file.cpp: CPPCHECK=1;PROJECT=Framework;_WIN32=1;WIN32=1;_MSC_VER=1400;_M_IX86=1;_DEBUG=1;XP_WIN=1;CPPCHECK=1;PROJECT=Framework;_WIN32=1;WIN32=1;_MSC_VER=1400;_M_IX86=1;_DEBUG=1;XP_WIN=1...
progress: TemplateSimplifier::simplifyTemplateInstantiations() 45%
progress: TemplateSimplifier::simplifyTemplateInstantiations() 28%
progress: TemplateSimplifier::simplifyTemplateInstantiations() 99%
progress: TemplateSimplifier::simplifyTemplateInstantiations() 16%
progress: TemplateSimplifier::simplifyTemplateInstantiations() 3%
progress: SymbolDatabase 0%

    Those template lines come out at a rate of about one every 30 seconds per file, where with 1.80 each file is processed in under a second.

    I've just built 1.84 (CentOS 7, FWIW) and it behaves the same way.

    Does anyone have any thoughts?

    (I can compare 1.81 and 1.82 if need be, but I'd have to download and build them first)

     

  • Neil Bird

    Neil Bird - 2018-07-13

    No, unfortunately it's proprietary, but it's visible at the get go (and as I said, in 1.83, so 1.84 changes aren't likely to be relevant) so it should be possible to create a cut down example.

    It won't be a trivial task, which is why I was hoping someone might have an idea off the bat!

    I'll see about building 1.81 & 1.82 as well so as to ID which release triggered the problem.

     

  • Daniel Marjamäki

    Daniel Marjamäki - 2018-07-13

    can you run 1.80 and 1.84 with the option --showtime=summary and then publish the results? It's enough if you run it on a single file.

     

    Last edit: Daniel Marjamäki 2018-07-13

  • Neil Bird

    Neil Bird - 2018-07-16

    I'm not sure what you were expecting out of the older versions, but it's not much! Does look like it was something that went in between 1.82 and 1.83. These are the results over one small file (that admitedly includes quite a few of our headers):

    1.80

    Tokenizer::createTokens: 0s (avg. 0s - 1 result(s))
Overall time: 0s

    1.81

    Tokenizer::createTokens: 0s (avg. 0s - 1 result(s))
Overall time: 0s

    1.82

    Tokenizer::createTokens: 0.01s (avg. 0.01s - 1 result(s))
Overall time: 0.01s

    1.83

    Tokenizer::simplifyTokens1: 98.1s (avg. 98.1s - 1 result(s))
Tokenizer::tokenize::simplifyTypedef: 3.23s (avg. 3.23s - 1 result(s))
Tokenizer::simplifyTokenList2: 1.51s (avg. 1.51s - 1 result(s))
Tokenizer::tokenize::setVarId: 1.24s (avg. 1.24s - 1 result(s))
UnusedVar::runChecks: 0.51s (avg. 0.51s - 1 result(s))
Tokenizer::createTokens: 0.44s (avg. 0.44s - 1 result(s))
Class::runSimplifiedChecks: 0.38s (avg. 0.38s - 1 result(s))
Other::runChecks: 0.1s (avg. 0.1s - 1 result(s))
STL usage::runSimplifiedChecks: 0.07s (avg. 0.07s - 1 result(s))
Sizeof::runChecks: 0.05s (avg. 0.05s - 1 result(s))
Type::runChecks: 0.05s (avg. 0.05s - 1 result(s))
IO using format string::runSimplifiedChecks: 0.04s (avg. 0.04s - 1 result(s))
Other::runSimplifiedChecks: 0.04s (avg. 0.04s - 1 result(s))
Tokenizer::tokenize::findGarbageCode: 0.04s (avg. 0.04s - 1 result(s))
Memory leaks (function variables)::runSimplifiedChecks: 0.04s (avg. 0.04s - 1 result(s))
Condition::runSimplifiedChecks: 0.04s (avg. 0.04s - 1 result(s))
Condition::runChecks: 0.03s (avg. 0.03s - 1 result(s))
Check function usage::runSimplifiedChecks: 0.03s (avg. 0.03s - 1 result(s))
Bounds checking::runSimplifiedChecks: 0.03s (avg. 0.03s - 1 result(s))
String::runSimplifiedChecks: 0.02s (avg. 0.02s - 1 result(s))
String::runChecks: 0.02s (avg. 0.02s - 1 result(s))
Uninitialized variables::runSimplifiedChecks: 0.02s (avg. 0.02s - 1 result(s))
Boolean::runSimplifiedChecks: 0.02s (avg. 0.02s - 1 result(s))
Memory leaks (address not taken)::runSimplifiedChecks: 0.02s (avg. 0.02s - 1 result(s))
Bounds checking::runChecks: 0.02s (avg. 0.02s - 1 result(s))
Vaarg::runSimplifiedChecks: 0.01s (avg. 0.01s - 1 result(s))
Assert::runSimplifiedChecks: 0.01s (avg. 0.01s - 1 result(s))
Auto Variables::runChecks: 0.01s (avg. 0.01s - 1 result(s))
Boolean::runChecks: 0.01s (avg. 0.01s - 1 result(s))
Null pointer::runSimplifiedChecks: 0.01s (avg. 0.01s - 1 result(s))
Null pointer::runChecks: 0.01s (avg. 0.01s - 1 result(s))
Using postfix operators::runChecks: 0.01s (avg. 0.01s - 1 result(s))
Leaks (auto variables)::runSimplifiedChecks: 0.01s (avg. 0.01s - 1 result(s))
IO using format string::runChecks: 0.01s (avg. 0.01s - 1 result(s))
Class::runChecks: 0.01s (avg. 0.01s - 1 result(s))
UnusedVar::runSimplifiedChecks: 0s (avg. 0s - 1 result(s))
Type::runSimplifiedChecks: 0s (avg. 0s - 1 result(s))
Uninitialized variables::runChecks: 0s (avg. 0s - 1 result(s))
Using postfix operators::runSimplifiedChecks: 0s (avg. 0s - 1 result(s))
Memory leaks (struct members)::runChecks: 0s (avg. 0s - 1 result(s))
Vaarg::runChecks: 0s (avg. 0s - 1 result(s))
Unused functions::runChecks: 0s (avg. 0s - 1 result(s))
Unused functions::runSimplifiedChecks: 0s (avg. 0s - 1 result(s))
Leaks (auto variables)::runChecks: 0s (avg. 0s - 1 result(s))
64-bit portability::runSimplifiedChecks: 0s (avg. 0s - 1 result(s))
Assert::runChecks: 0s (avg. 0s - 1 result(s))
Auto Variables::runSimplifiedChecks: 0s (avg. 0s - 1 result(s))
Boost usage::runChecks: 0s (avg. 0s - 1 result(s))
Boost usage::runSimplifiedChecks: 0s (avg. 0s - 1 result(s))
Check function usage::runChecks: 0s (avg. 0s - 1 result(s))
Exception Safety::runChecks: 0s (avg. 0s - 1 result(s))
Exception Safety::runSimplifiedChecks: 0s (avg. 0s - 1 result(s))
Sizeof::runSimplifiedChecks: 0s (avg. 0s - 1 result(s))
Memory leaks (address not taken)::runChecks: 0s (avg. 0s - 1 result(s))
Memory leaks (class variables)::runChecks: 0s (avg. 0s - 1 result(s))
Memory leaks (class variables)::runSimplifiedChecks: 0s (avg. 0s - 1 result(s))
Memory leaks (function variables)::runChecks: 0s (avg. 0s - 1 result(s))
64-bit portability::runChecks: 0s (avg. 0s - 1 result(s))
Memory leaks (struct members)::runSimplifiedChecks: 0s (avg. 0s - 1 result(s))
STL usage::runChecks: 0s (avg. 0s - 1 result(s))
Overall time: 106.19s

    1.84

    Tokenizer::simplifyTokens1: 97.95s (avg. 97.95s - 1 result(s))
Tokenizer::tokenize::simplifyTypedef: 4.4s (avg. 4.4s - 1 result(s))
Tokenizer::simplifyTokenList2: 1.44s (avg. 1.44s - 1 result(s))
Tokenizer::tokenize::setVarId: 1.27s (avg. 1.27s - 1 result(s))
UnusedVar::runChecks: 0.57s (avg. 0.57s - 1 result(s))
Class::runSimplifiedChecks: 0.47s (avg. 0.47s - 1 result(s))
Tokenizer::createTokens: 0.42s (avg. 0.42s - 1 result(s))
Other::runChecks: 0.1s (avg. 0.1s - 1 result(s))
STL usage::runSimplifiedChecks: 0.07s (avg. 0.07s - 1 result(s))
Other::runSimplifiedChecks: 0.06s (avg. 0.06s - 1 result(s))
Type::runChecks: 0.05s (avg. 0.05s - 1 result(s))
Sizeof::runChecks: 0.05s (avg. 0.05s - 1 result(s))
Condition::runSimplifiedChecks: 0.05s (avg. 0.05s - 1 result(s))
Tokenizer::tokenize::findGarbageCode: 0.04s (avg. 0.04s - 1 result(s))
Memory leaks (function variables)::runSimplifiedChecks: 0.04s (avg. 0.04s - 1 result(s))
IO using format string::runSimplifiedChecks: 0.04s (avg. 0.04s - 1 result(s))
Check function usage::runSimplifiedChecks: 0.04s (avg. 0.04s - 1 result(s))
Condition::runChecks: 0.03s (avg. 0.03s - 1 result(s))
Null pointer::runSimplifiedChecks: 0.02s (avg. 0.02s - 1 result(s))
Null pointer::runChecks: 0.02s (avg. 0.02s - 1 result(s))
String::runChecks: 0.02s (avg. 0.02s - 1 result(s))
String::runSimplifiedChecks: 0.02s (avg. 0.02s - 1 result(s))
Leaks (auto variables)::runSimplifiedChecks: 0.02s (avg. 0.02s - 1 result(s))
Uninitialized variables::runSimplifiedChecks: 0.02s (avg. 0.02s - 1 result(s))
Memory leaks (address not taken)::runSimplifiedChecks: 0.02s (avg. 0.02s - 1 result(s))
Boolean::runChecks: 0.02s (avg. 0.02s - 1 result(s))
Bounds checking::runSimplifiedChecks: 0.02s (avg. 0.02s - 1 result(s))
Vaarg::runSimplifiedChecks: 0.01s (avg. 0.01s - 1 result(s))
Assert::runSimplifiedChecks: 0.01s (avg. 0.01s - 1 result(s))
Auto Variables::runSimplifiedChecks: 0.01s (avg. 0.01s - 1 result(s))
Boolean::runSimplifiedChecks: 0.01s (avg. 0.01s - 1 result(s))
Boost usage::runSimplifiedChecks: 0.01s (avg. 0.01s - 1 result(s))
Bounds checking::runChecks: 0.01s (avg. 0.01s - 1 result(s))
Check function usage::runChecks: 0.01s (avg. 0.01s - 1 result(s))
Exception Safety::runSimplifiedChecks: 0.01s (avg. 0.01s - 1 result(s))
IO using format string::runChecks: 0.01s (avg. 0.01s - 1 result(s))
64-bit portability::runChecks: 0.01s (avg. 0.01s - 1 result(s))
UnusedVar::runSimplifiedChecks: 0s (avg. 0s - 1 result(s))
Using postfix operators::runChecks: 0s (avg. 0s - 1 result(s))
Unused functions::runSimplifiedChecks: 0s (avg. 0s - 1 result(s))
Type::runSimplifiedChecks: 0s (avg. 0s - 1 result(s))
Uninitialized variables::runChecks: 0s (avg. 0s - 1 result(s))
Using postfix operators::runSimplifiedChecks: 0s (avg. 0s - 1 result(s))
Memory leaks (struct members)::runChecks: 0s (avg. 0s - 1 result(s))
Vaarg::runChecks: 0s (avg. 0s - 1 result(s))
Unused functions::runChecks: 0s (avg. 0s - 1 result(s))
Sizeof::runSimplifiedChecks: 0s (avg. 0s - 1 result(s))
STL usage::runChecks: 0s (avg. 0s - 1 result(s))
Memory leaks (struct members)::runSimplifiedChecks: 0s (avg. 0s - 1 result(s))
Memory leaks (function variables)::runChecks: 0s (avg. 0s - 1 result(s))
Memory leaks (class variables)::runSimplifiedChecks: 0s (avg. 0s - 1 result(s))
Memory leaks (class variables)::runChecks: 0s (avg. 0s - 1 result(s))
Memory leaks (address not taken)::runChecks: 0s (avg. 0s - 1 result(s))
Leaks (auto variables)::runChecks: 0s (avg. 0s - 1 result(s))
Exception Safety::runChecks: 0s (avg. 0s - 1 result(s))
Class::runChecks: 0s (avg. 0s - 1 result(s))
Boost usage::runChecks: 0s (avg. 0s - 1 result(s))
Auto Variables::runChecks: 0s (avg. 0s - 1 result(s))
Assert::runChecks: 0s (avg. 0s - 1 result(s))
64-bit portability::runSimplifiedChecks: 0s (avg. 0s - 1 result(s))
Overall time: 107.37s
     

  • Neil Bird

    Neil Bird - 2018-07-16

    BTW, I see this sort of odd counting a lot:

    progress: TemplateSimplifier::simplifyTemplateInstantiations() 20%
progress: TemplateSimplifier::simplifyTemplateInstantiations() 28%
progress: TemplateSimplifier::simplifyTemplateInstantiations() 19%
progress: TemplateSimplifier::simplifyTemplateInstantiations() 99%
progress: TemplateSimplifier::simplifyTemplateInstantiations() 11%
progress: TemplateSimplifier::simplifyTemplateInstantiations() 6%
     

  • Neil Bird

    Neil Bird - 2018-07-16

    I don't hold out much hope producing a cut-down example, the slow down appears to be, if not linear, then a scale factor of the volume of code. The (awaiting moderation) timings are from a file in our third library to build, which will be including the library headers of the fist two libraries (plus a couple of local ones).

    Hiding library 2's headers (~3000 SLOC) drops the run time from 107s to 93s; hiding the first (~18,000 SLOC) as well takes it to 8s.

    Vs., of course, e.g., 1.82's 0.01s.

    Oh. OK. <checks using="" strace="">

    Damn, that complicates matters. Prior to 1.83, those headers weren't being included. This is likely down to an old bug that mishandled macros in #include statements (which we use). I suspect, then, that that was fixed in 1.83 (hmm, that may even be why I was awaiting that version ...) and now we're seeing all headers being processed (for all files).

    So the slow down from my perspective has potentially been there for quite some time, but hidden by files only being able to see their local headers.

    Not sure where I can go from here; I think I'll just have to remove the -I option to mimic the old process and suffer the loss of the better diagnostics that would give me.

    Maybe I'll trigger a weekly job to run the whole lot; I don' t know yet how long that will take to finish!

     

Log in to post a comment.

Want the latest updates on software, tech news, and AI?
Get latest updates about software, tech news, and AI from SourceForge directly in your inbox once a month.