Menu

performance since 1.82

2019-02-01
2019-03-05
1 2 > >> (Page 1 of 2)
  • Fullmetal Bender

    Hi! I just update my cppcheck from 1.77 to 1.86 and noticed then new version is 4 times slover.
    I find that 1.82 is slover then 1.81.

    cppcheck-1.81$ \time ./cppcheck Main.cpp tooks "10.82user 0.01system 0:10.83elapsed"

    and

    cppcheck-1.82$ \time ./cppcheck Main.cpp tooks "46.29user 0.01system 0:46.30elapsed"

    Is this expected ?

     
  • Daniel Marjamäki

    That is not expected in general. But I think it sometimes happen in a few cases.

    We keep improving the parser and that means more analysis is done.. then getting a corresponding time increase is something we expect. This primarily affects C++ code that uses templates. Does that sound like your code?

    Could you run cppcheck with "unofficial" flag --showtime=summary? That can give us some details.

     

    Last edit: Daniel Marjamäki 2019-02-01
  • Fullmetal Bender

    Yes, our code is c++ with templates
    (when using --report-progress I see often
    progress: TemplateSimplifier::simplifyTemplateInstantiations() 81% )

    top 5 for 1.86:

    Tokenizer::simplifyTokens1: 48.2073s (avg. 4.82073s - 10 result(s))
    Tokenizer::tokenize::setVarId: 16.328s (avg. 1.6328s - 10 result(s))
    Tokenizer::simplifyTokenList2: 4.87837s (avg. 0.813062s - 6 result(s))
    Tokenizer::tokenize::simplifyTypedef: 0.414468s (avg. 0.0414468s - 10 result(s))
    Tokenizer::createTokens: 0.383731s (avg. 0.0383731s - 10 result(s))
    

    top 5 for 1.82

    Tokenizer::simplifyTokens1: 40.2213s (avg. 4.02213s - 10 result(s))
    Tokenizer::tokenize::setVarId: 7.99151s (avg. 0.799151s - 10 result(s))
    Tokenizer::simplifyTokenList2: 4.62758s (avg. 0.771263s - 6 result(s))
    Tokenizer::tokenize::simplifyTypedef: 0.414088s (avg. 0.0414088s - 10 result(s))
    Tokenizer::createTokens: 0.397232s (avg. 0.0397232s - 10 result(s))
    

    top 5 for 1.81:

    Tokenizer::simplifyTokens1: 5.3574s (avg. 0.53574s - 10 result(s))
    Tokenizer::simplifyTokenList2: 3.34461s (avg. 0.557435s - 6 result(s))
    Tokenizer::tokenize::setVarId: 0.534465s (avg. 0.0534465s - 10 result(s))
    Tokenizer::tokenize::simplifyTypedef: 0.404231s (avg. 0.0404231s - 10 result(s))
    Tokenizer::createTokens: 0.366861s (avg. 0.0366861s - 10 result(s))
    
     
    • Markus Elfring

      Markus Elfring - 2019-02-01

      Yes, our code is c++ with templates

      • Can you share any more statistics for the analysed source code structure?
      • Do you find data processing characteristics especially remarkable for any specific source files?
       
      • Fullmetal Bender

        what kind of statistics do you need?
        I just run cppcheck on project folder, so I dont have processing time for each file, but I will try to measure it

         
        • Markus Elfring

          Markus Elfring - 2019-02-01
          • Will file sizes matter in significant ways?
          • Which C++ structures did become more challenging for efficient source code analysis?
           

          Last edit: Markus Elfring 2019-02-01
    • Daniel Marjamäki

      1.81:

      Tokenizer::tokenize::setVarId: 0.534465s (avg. 0.0534465s - 10 result(s))
      

      1.86:

      Tokenizer::tokenize::setVarId: 16.328s (avg. 1.6328s - 10 result(s))
      

      I am confused about such difference. As far as I remember we have not made drastic changes in this part of Cppcheck.

       
      • Markus Elfring

        Markus Elfring - 2019-03-01

        The changes for these software versions resulted in a significant difference for the shown run time behaviour.
        Are you becoming more interested in precise software profiling?

         

        Last edit: Markus Elfring 2019-03-01
  • Daniel Marjamäki

    Thanks for the stats. Yes now we can see that the "parsing" got a lot slower.

    To make it more deterministic. Please remove "-f" or "--force" if you use that. Please use at least one "-D"..

    I don't want to say that it is "expected". But I do not know how to determine if this is some problem that should be looking into.. I assume your code is not open source?

    I don't remember if there is some useful debug output that we can use here. If there are not.. Would you be willing to run patched Cppcheck also that shows if there are lots of skipped code? You can easily compile Cppcheck yourself if you want..

     
    • Markus Elfring

      Markus Elfring - 2019-02-01

      But I do not know how to determine if this is some problem that should be looking into.

      Do you need any more help for the systematic comparison of run time characteristics?

       
  • Fullmetal Bender

    Yes, our code is not open source. We do not user -f option. On mondey I will talk with our main developper about -D option because I'm not a developper and don't know what macro can be defined.

    I can run patched cppcheck
    I also see there are options --debug-normal and --debug-simplified, i will try to compare output from different versions

     
  • Fullmetal Bender

    Looks like I found candidate for slow parsnig (see attachment)
    ./cppcheck --showtime=top5 ~/downloads/btflag_test.cpp
    v1.81 - Tokenizer::simplifyTokens1: 0.028685s
    v1.82 - Tokenizer::simplifyTokens1: 0.041139s
    ~ +30%

     
  • Daniel Marjamäki

    thanks. I would have preferred a larger time difference than +30%. Didn't you find such candidate at all? Or are those source code that you can't share?

    It is good that you can run a patched cppcheck. To start with I am thinking we can try to achieve more detailed measurements.

     
    • Markus Elfring

      Markus Elfring - 2019-02-09

      Would you like to improve the software build infrastructure for corresponding program profiling anyhow?

       
  • Fullmetal Bender

    Our project is too big (860 files), and I don't know how to deremine wich files are most slow. I took one file, and began to check all its includes. The includes count is very big, and after 1 hour I ended with many files, each has a small additional time to check.

    Is it possible to get more detailed information about Tokenizer to deremine what part of file (or what icluded file or template) was slowest?

     
    • Markus Elfring

      Markus Elfring - 2019-02-09

      Our project is too big …

      I would prefer to interpret the software situation in more constructive ways.
      Efficient data processing will be more helpful here, won't it?

      and I don't know how to deremine wich files are most slow.

      • How do you think about to share any information from the file size distribution?
      • Would you like to check the run time behaviour for code analysis on the biggest source file?
       
      • Fullmetal Bender

        860 cpp and h files. Size from 20 bytes to 73kB. Total size is 20MB.
        Checking biggest file (72KB) takes 0,1second, while checking 1KB file take 4 seconds. Little file can include 100 other files, so file size doesn't matter.

        Even having found the most slover cpp file the question will still be open, because it can contain more then 100 includes. Checking of .h files is very quick, but checking of cpp file that only include .h files is much slover

         
        • Markus Elfring

          Markus Elfring - 2019-02-09

          …, while checking 1KB file take 4 seconds.

          • Does the source code analysis result in any more run times which you find significant for your work flow?
          • Would you like to distinguish relevant files by priority?

          Little file can include 100 other files,

          • Do you maintain such a list manually?
          • Were any inclusion specifications automatically generated?

          so file size doesn't matter.

          Other software details will become more interesting then, won't they?

          Do you recognise any special code patterns in the source files with remarkable data processing durations?

           
  • Robert Reif

    Robert Reif - 2019-02-09

    Here are the results for the supplied file for the last 8 versions:

    ~/cppcheck-1.87/cppcheck --enable=all --inconclusive btflag_test.cpp --showtime=top5
    Tokenizer::simplifyTokens1: 0.067576s (avg. 0.067576s - 1 result(s))
    Tokenizer::tokenize::simplifyTemplates: 0.040415s (avg. 0.040415s - 1 result(s))
    Tokenizer::simplifyTokenList2: 0.028522s (avg. 0.028522s - 1 result(s))
    Tokenizer::simplifyTokens1::createSymbolDatabase: 0.006933s (avg. 0.006933s - 1 result(s))
    Tokenizer::simplifyTokens1::ValueFlow: 0.003762s (avg. 0.003762s - 1 result(s))
    Overall time: 0.170267s
    
    ~/cppcheck-1.86/cppcheck --enable=all --inconclusive btflag_test.cpp --showtime=top5
    Tokenizer::simplifyTokens1: 0.066205s (avg. 0.066205s - 1 result(s))
    Tokenizer::simplifyTokenList2: 0.026576s (avg. 0.026576s - 1 result(s))
    Tokenizer::tokenize::setVarId: 0.003268s (avg. 0.003268s - 1 result(s))
    UnusedVar::runChecks: 0.001944s (avg. 0.001944s - 1 result(s))
    Other::runChecks: 0.00129s (avg. 0.00129s - 1 result(s))
    Overall time: 0.109085s
    
    ~/cppcheck-1.85/cppcheck --enable=all --inconclusive btflag_test.cpp --showtime=top5
    Tokenizer::simplifyTokens1: 0.072896s (avg. 0.072896s - 1 result(s))
    Tokenizer::simplifyTokenList2: 0.025682s (avg. 0.025682s - 1 result(s))
    Tokenizer::tokenize::setVarId: 0.003034s (avg. 0.003034s - 1 result(s))
    UnusedVar::runChecks: 0.002052s (avg. 0.002052s - 1 result(s))
    Other::runChecks: 0.001763s (avg. 0.001763s - 1 result(s))
    Overall time: 0.116141s
    
    ~/cppcheck-1.84/cppcheck --enable=all --inconclusive btflag_test.cpp --showtime=top5
    Tokenizer::simplifyTokens1: 0.058096s (avg. 0.058096s - 1 result(s))
    Tokenizer::simplifyTokenList2: 0.022692s (avg. 0.022692s - 1 result(s))
    Tokenizer::tokenize::setVarId: 0.003019s (avg. 0.003019s - 1 result(s))
    UnusedVar::runChecks: 0.002077s (avg. 0.002077s - 1 result(s))
    Other::runChecks: 0.001639s (avg. 0.001639s - 1 result(s))
    Overall time: 0.097839s
    
    ~/cppcheck-1.83/cppcheck --enable=all --inconclusive btflag_test.cpp --showtime=top5
    Tokenizer::simplifyTokens1: 0.069596s (avg. 0.069596s - 1 result(s))
    Tokenizer::simplifyTokenList2: 0.022957s (avg. 0.022957s - 1 result(s))
    Tokenizer::tokenize::setVarId: 0.003169s (avg. 0.003169s - 1 result(s))
    UnusedVar::runChecks: 0.001779s (avg. 0.001779s - 1 result(s))
    Other::runChecks: 0.001388s (avg. 0.001388s - 1 result(s))
    Overall time: 0.109047s
    
    ~/cppcheck-1.82/cppcheck --enable=all --inconclusive btflag_test.cpp --showtime=top5
    Tokenizer::simplifyTokens1: 0.069584s (avg. 0.069584s - 1 result(s))
    Tokenizer::simplifyTokenList2: 0.023304s (avg. 0.023304s - 1 result(s))
    Tokenizer::tokenize::setVarId: 0.003086s (avg. 0.003086s - 1 result(s))
    UnusedVar::runChecks: 0.001904s (avg. 0.001904s - 1 result(s))
    Other::runChecks: 0.001423s (avg. 0.001423s - 1 result(s))
    Overall time: 0.109219s
    
    ~/cppcheck-1.81/cppcheck --enable=all --inconclusive btflag_test.cpp --showtime=top5
    Tokenizer::simplifyTokens1: 0.047939s (avg. 0.047939s - 1 result(s))
    Tokenizer::simplifyTokenList2: 0.023389s (avg. 0.023389s - 1 result(s))
    Tokenizer::tokenize::setVarId: 0.002525s (avg. 0.002525s - 1 result(s))
    UnusedVar::runChecks: 0.001768s (avg. 0.001768s - 1 result(s))
    Other::runChecks: 0.001476s (avg. 0.001476s - 1 result(s))
    Overall time: 0.086746s
    
    ~/cppcheck-1.80/cppcheck --enable=all --inconclusive btflag_test.cpp --showtime=top5
    Tokenizer::simplifyTokens1: 0.047898s (avg. 0.047898s - 1 result(s))
    Tokenizer::simplifyTokenList2: 0.02365s (avg. 0.02365s - 1 result(s))
    Tokenizer::tokenize::setVarId: 0.002491s (avg. 0.002491s - 1 result(s))
    UnusedVar::runChecks: 0.001679s (avg. 0.001679s - 1 result(s))
    Other::runChecks: 0.001371s (avg. 0.001371s - 1 result(s))
    Overall time: 0.086746s
    

    1.87 is the first version that can fully process and understand the supplied file. It is also the slowest.

     
  • Fullmetal Bender

    Hi. Any news?

     
  • Andrew

    Andrew - 2019-02-28

    I'm also seeing a big slowdown with CppCheck 1.82, but I can see huge timing gaps in the output:

    1.81
    [20:55:20][Step 1/2] in directory: D:\Data\TeamCity\buildAgent\work\Facade_0.0.0
    [20:55:33][Step 1/2] Checking Utils\Reader.cpp Debug|Win32...
    ...
    [20:55:33][Step 1/2] Checking Facade\AlgoCSAFOSystems.cpp Release|x64...
    [20:55:34][Step 1/2] Checking Facade\AlgoCSAForTrades.cpp: _MSC_VER=1900;_WIN32=1;...

    1.82
    [20:39:42][Step 1/2] in directory: D:\Data\TeamCity\buildAgent\work\Facade_0.0.0
    [20:42:09][Step 1/2] Checking Utils\Reader.cpp Debug|Win32...
    ...
    [20:42:09][Step 1/2] Checking Facade\AlgoCSAFOSystems.cpp Release|x64...
    [20:44:46][Step 1/2] Checking Facade\AlgoCSAForTrades.cpp: _WIN32=1;...

    I'd really like to see this resolved so I can upgrade - it's not practical as it stands.

    If there's any log details I can collect please let me know. I can't share the source code though.

     
  • Robert Reif

    Robert Reif - 2019-03-01

    Have you tried the latest version (1.87) or git head? 1.82 is over a year old. Improvements and fixes are only made to the latest version.

    I would expect newer versions to be slower because we are adding more checks and improving the accuarcy of the checks. Both generally require more CPU time. However a large change may be due to a bug but that would probably effect specific files rather than a overall slowdown.

    Is your source code open source? Performance is highly dependent on the source code being checked.

     
    • Andrew

      Andrew - 2019-03-01

      I first upgraded to 1.87 (from 1.80) and noticed a slowdown. I then narrowed it down to an upgrade from 1.81 to 1.82 in case it helped isolate the change.

       
  • Daniel Marjamäki

    I doubt we will be able to "solve" this by making full Cppcheck analysis drastically faster. unless we find some horrible hotspot. I believe it's unlikely that there is a horrible hotspot.

    Do you use the released binaries or did you compile yourself? It is very important that our "match compiler" is used during compilation.

    Maybe you need some way to tweak Cppcheck analysis? Maybe there are some analysis steps that does not give you enough good results.
    You might be interested to have a "limited" analysis at daytime and then a "full" analysis in nightly builds?

     
  • Daniel Marjamäki

    For instance we could have a "fast" option that will skip all template code. I wonder, how interesting does such option sound if it means significantly faster analysis?

     
1 2 > >> (Page 1 of 2)

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.