[PATCH] D63227: [analyzer] Better timers.
This revision was automatically updated to reflect the committed changes. Closed by commit rL364266: [analyzer] Add more timers for performance profiling. (authored by dergachev, committed by ). Herald added a project: LLVM. Herald added a subscriber: llvm-commits. Changed prior to commit: https://reviews.llvm.org/D63227?vs=204353&id=206352#toc Repository: rL LLVM CHANGES SINCE LAST ACTION https://reviews.llvm.org/D63227/new/ https://reviews.llvm.org/D63227 Files: cfe/trunk/include/clang/StaticAnalyzer/Core/PathSensitive/ExprEngine.h cfe/trunk/lib/StaticAnalyzer/Core/ExprEngine.cpp cfe/trunk/lib/StaticAnalyzer/Frontend/AnalysisConsumer.cpp Index: cfe/trunk/lib/StaticAnalyzer/Core/ExprEngine.cpp === --- cfe/trunk/lib/StaticAnalyzer/Core/ExprEngine.cpp +++ cfe/trunk/lib/StaticAnalyzer/Core/ExprEngine.cpp @@ -225,10 +225,6 @@ } } -ExprEngine::~ExprEngine() { - BR.FlushReports(); -} - //===--===// // Utility methods. //===--===// Index: cfe/trunk/lib/StaticAnalyzer/Frontend/AnalysisConsumer.cpp === --- cfe/trunk/lib/StaticAnalyzer/Frontend/AnalysisConsumer.cpp +++ cfe/trunk/lib/StaticAnalyzer/Frontend/AnalysisConsumer.cpp @@ -196,7 +196,9 @@ /// Time the analyzes time of each translation unit. std::unique_ptr AnalyzerTimers; - std::unique_ptr TUTotalTimer; + std::unique_ptr SyntaxCheckTimer; + std::unique_ptr ExprEngineTimer; + std::unique_ptr BugReporterTimer; /// The information about analyzed functions shared throughout the /// translation unit. @@ -212,8 +214,13 @@ if (Opts->PrintStats || Opts->ShouldSerializeStats) { AnalyzerTimers = llvm::make_unique( "analyzer", "Analyzer timers"); - TUTotalTimer = llvm::make_unique( - "time", "Analyzer total time", *AnalyzerTimers); + SyntaxCheckTimer = llvm::make_unique( + "syntaxchecks", "Syntax-based analysis time", *AnalyzerTimers); + ExprEngineTimer = llvm::make_unique( + "exprengine", "Path exploration time", *AnalyzerTimers); + BugReporterTimer = llvm::make_unique( + "bugreporter", "Path-sensitive report post-processing time", + *AnalyzerTimers); llvm::EnableStatistics(/* PrintOnExit= */ false); } } @@ -346,8 +353,13 @@ /// Handle callbacks for arbitrary Decls. bool VisitDecl(Decl *D) { AnalysisMode Mode = getModeForDecl(D, RecVisitorMode); -if (Mode & AM_Syntax) +if (Mode & AM_Syntax) { + if (SyntaxCheckTimer) +SyntaxCheckTimer->startTimer(); checkerMgr->runCheckersOnASTDecl(D, *Mgr, *RecVisitorBR); + if (SyntaxCheckTimer) +SyntaxCheckTimer->stopTimer(); +} return true; } @@ -566,7 +578,11 @@ void AnalysisConsumer::runAnalysisOnTranslationUnit(ASTContext &C) { BugReporter BR(*Mgr); TranslationUnitDecl *TU = C.getTranslationUnitDecl(); + if (SyntaxCheckTimer) +SyntaxCheckTimer->startTimer(); checkerMgr->runCheckersOnASTDecl(TU, *Mgr, BR); + if (SyntaxCheckTimer) +SyntaxCheckTimer->stopTimer(); // Run the AST-only checks using the order in which functions are defined. // If inlining is not turned on, use the simplest function order for path @@ -608,8 +624,6 @@ if (Diags.hasErrorOccurred() || Diags.hasFatalErrorOccurred()) return; - if (TUTotalTimer) TUTotalTimer->startTimer(); - if (isBisonFile(C)) { reportAnalyzerProgress("Skipping bison-generated file\n"); } else if (Opts->DisableAllChecks) { @@ -622,8 +636,6 @@ runAnalysisOnTranslationUnit(C); } - if (TUTotalTimer) TUTotalTimer->stopTimer(); - // Count how many basic blocks we have not covered. NumBlocksInAnalyzedFunctions = FunctionSummaries.getTotalNumBasicBlocks(); NumVisitedBlocksInAnalyzedFunctions = @@ -747,8 +759,13 @@ BugReporter BR(*Mgr); - if (Mode & AM_Syntax) + if (Mode & AM_Syntax) { +if (SyntaxCheckTimer) + SyntaxCheckTimer->startTimer(); checkerMgr->runCheckersOnASTBody(D, *Mgr, BR); +if (SyntaxCheckTimer) + SyntaxCheckTimer->stopTimer(); + } if ((Mode & AM_Path) && checkerMgr->hasPathSensitiveCheckers()) { RunPathSensitiveChecks(D, IMode, VisitedCallees); if (IMode != ExprEngine::Inline_Minimal) @@ -775,8 +792,12 @@ ExprEngine Eng(CTU, *Mgr, VisitedCallees, &FunctionSummaries, IMode); // Execute the worklist algorithm. + if (ExprEngineTimer) +ExprEngineTimer->startTimer(); Eng.ExecuteWorkList(Mgr->getAnalysisDeclContextManager().getStackFrame(D), Mgr->options.MaxNodesPerTopLevelFunction); + if (ExprEngineTimer) +ExprEngineTimer->stopTimer(); if (!Mgr->options.DumpExplodedGraphTo.empty()) Eng.DumpGraph(Mgr->options.TrimGraph, Mgr->options.DumpExplodedGraph
[PATCH] D63227: [analyzer] Better timers.
xazax.hun added inline comments. Comment at: clang/lib/StaticAnalyzer/Core/ExprEngine.cpp:228 -ExprEngine::~ExprEngine() { - BR.FlushReports(); NoQ wrote: > xazax.hun wrote: > > Hmm. Maybe add an assert that all the bug reports are flushed at this > > point? Just to make sure we never need this :) I am not insisting on this > > change just wondering. > Actually we already have the same code in `~BugReporter` itself, so this > assertion would be kinda trivial. Like, it wouldn't necessarily hold, as the > destructor for the field hasn't been executed at this point, but it's still > useless, because the destructor will be executed very soon. Makes sense, thanks. Repository: rC Clang CHANGES SINCE LAST ACTION https://reviews.llvm.org/D63227/new/ https://reviews.llvm.org/D63227 ___ cfe-commits mailing list cfe-commits@lists.llvm.org https://lists.llvm.org/cgi-bin/mailman/listinfo/cfe-commits
[PATCH] D63227: [analyzer] Better timers.
NoQ marked an inline comment as done. NoQ added inline comments. Comment at: clang/lib/StaticAnalyzer/Core/ExprEngine.cpp:228 -ExprEngine::~ExprEngine() { - BR.FlushReports(); xazax.hun wrote: > Hmm. Maybe add an assert that all the bug reports are flushed at this point? > Just to make sure we never need this :) I am not insisting on this change > just wondering. Actually we already have the same code in `~BugReporter` itself, so this assertion would be kinda trivial. Like, it wouldn't necessarily hold, as the destructor for the field hasn't been executed at this point, but it's still useless, because the destructor will be executed very soon. Repository: rC Clang CHANGES SINCE LAST ACTION https://reviews.llvm.org/D63227/new/ https://reviews.llvm.org/D63227 ___ cfe-commits mailing list cfe-commits@lists.llvm.org https://lists.llvm.org/cgi-bin/mailman/listinfo/cfe-commits
[PATCH] D63227: [analyzer] Better timers.
xazax.hun added inline comments. Comment at: clang/lib/StaticAnalyzer/Core/ExprEngine.cpp:228 -ExprEngine::~ExprEngine() { - BR.FlushReports(); Hmm. Maybe add an assert that all the bug reports are flushed at this point? Just to make sure we never need this :) I am not insisting on this change just wondering. Repository: rC Clang CHANGES SINCE LAST ACTION https://reviews.llvm.org/D63227/new/ https://reviews.llvm.org/D63227 ___ cfe-commits mailing list cfe-commits@lists.llvm.org https://lists.llvm.org/cgi-bin/mailman/listinfo/cfe-commits
[PATCH] D63227: [analyzer] Better timers.
xazax.hun accepted this revision. xazax.hun added a comment. This revision is now accepted and ready to land. Looks good :) More diagnostics are always welcome. Repository: rC Clang CHANGES SINCE LAST ACTION https://reviews.llvm.org/D63227/new/ https://reviews.llvm.org/D63227 ___ cfe-commits mailing list cfe-commits@lists.llvm.org https://lists.llvm.org/cgi-bin/mailman/listinfo/cfe-commits
[PATCH] D63227: [analyzer] Better timers.
NoQ created this revision. NoQ added reviewers: dcoughlin, xazax.hun, a_sidorin, rnkovacs, Szelethus, baloghadamsoftware, Charusso. Herald added subscribers: cfe-commits, dkrupp, donat.nagy, mikhail.ramalho, a.sidorin, szepet. Herald added a project: clang. `-analyzer-stats` now allows you to find out how much time was spent on AST-based analysis and on path-sensitive analysis and, separately, on bug visitors, as they're occasionally a performance problem on their own. The total timer wasn't useful because there's anyway a total time printed out, so i removed it. Accidentally remove the `ExprEngine`'s destructor because it's not really useful: reports are flushed manually anyway, which i've noticed while adding a timer. Sample output: ===-=== Analyzer timers ===-=== Total Execution Time: 7.4278 seconds (7.4293 wall clock) ---User Time--- --System Time-- --User+System-- ---Wall Time--- --- Name --- 7.2345 ( 99.0%) 0.1140 ( 96.9%) 7.3485 ( 98.9%) 7.3500 ( 98.9%) Path exploration time 0.0456 ( 0.6%) 0.0026 ( 2.2%) 0.0482 ( 0.6%) 0.0482 ( 0.6%) Path-sensitive report post-processing time 0.0300 ( 0.4%) 0.0011 ( 1.0%) 0.0311 ( 0.4%) 0.0312 ( 0.4%) Syntax-based analysis time 7.3101 (100.0%) 0.1177 (100.0%) 7.4278 (100.0%) 7.4293 (100.0%) Total Repository: rC Clang https://reviews.llvm.org/D63227 Files: clang/include/clang/StaticAnalyzer/Core/PathSensitive/ExprEngine.h clang/lib/StaticAnalyzer/Core/ExprEngine.cpp clang/lib/StaticAnalyzer/Frontend/AnalysisConsumer.cpp Index: clang/lib/StaticAnalyzer/Frontend/AnalysisConsumer.cpp === --- clang/lib/StaticAnalyzer/Frontend/AnalysisConsumer.cpp +++ clang/lib/StaticAnalyzer/Frontend/AnalysisConsumer.cpp @@ -196,7 +196,9 @@ /// Time the analyzes time of each translation unit. std::unique_ptr AnalyzerTimers; - std::unique_ptr TUTotalTimer; + std::unique_ptr SyntaxCheckTimer; + std::unique_ptr ExprEngineTimer; + std::unique_ptr BugReporterTimer; /// The information about analyzed functions shared throughout the /// translation unit. @@ -212,8 +214,13 @@ if (Opts->PrintStats || Opts->ShouldSerializeStats) { AnalyzerTimers = llvm::make_unique( "analyzer", "Analyzer timers"); - TUTotalTimer = llvm::make_unique( - "time", "Analyzer total time", *AnalyzerTimers); + SyntaxCheckTimer = llvm::make_unique( + "syntaxchecks", "Syntax-based analysis time", *AnalyzerTimers); + ExprEngineTimer = llvm::make_unique( + "exprengine", "Path exploration time", *AnalyzerTimers); + BugReporterTimer = llvm::make_unique( + "bugreporter", "Path-sensitive report post-processing time", + *AnalyzerTimers); llvm::EnableStatistics(/* PrintOnExit= */ false); } } @@ -346,8 +353,13 @@ /// Handle callbacks for arbitrary Decls. bool VisitDecl(Decl *D) { AnalysisMode Mode = getModeForDecl(D, RecVisitorMode); -if (Mode & AM_Syntax) +if (Mode & AM_Syntax) { + if (SyntaxCheckTimer) +SyntaxCheckTimer->startTimer(); checkerMgr->runCheckersOnASTDecl(D, *Mgr, *RecVisitorBR); + if (SyntaxCheckTimer) +SyntaxCheckTimer->stopTimer(); +} return true; } @@ -566,7 +578,11 @@ void AnalysisConsumer::runAnalysisOnTranslationUnit(ASTContext &C) { BugReporter BR(*Mgr); TranslationUnitDecl *TU = C.getTranslationUnitDecl(); + if (SyntaxCheckTimer) +SyntaxCheckTimer->startTimer(); checkerMgr->runCheckersOnASTDecl(TU, *Mgr, BR); + if (SyntaxCheckTimer) +SyntaxCheckTimer->stopTimer(); // Run the AST-only checks using the order in which functions are defined. // If inlining is not turned on, use the simplest function order for path @@ -608,8 +624,6 @@ if (Diags.hasErrorOccurred() || Diags.hasFatalErrorOccurred()) return; - if (TUTotalTimer) TUTotalTimer->startTimer(); - if (isBisonFile(C)) { reportAnalyzerProgress("Skipping bison-generated file\n"); } else if (Opts->DisableAllChecks) { @@ -622,8 +636,6 @@ runAnalysisOnTranslationUnit(C); } - if (TUTotalTimer) TUTotalTimer->stopTimer(); - // Count how many basic blocks we have not covered. NumBlocksInAnalyzedFunctions = FunctionSummaries.getTotalNumBasicBlocks(); NumVisitedBlocksInAnalyzedFunctions = @@ -747,8 +759,13 @@ BugReporter BR(*Mgr); - if (Mode & AM_Syntax) + if (Mode & AM_Syntax) { +if (SyntaxCheckTimer) + SyntaxCheckTimer->startTimer(); checkerMgr->runCheckersOnASTBody(D, *Mgr, BR); +if (SyntaxCheckTimer) + SyntaxCheckTimer->stopTimer(); + } if ((Mode & AM_Path) && checkerMgr->hasPathSensitiveCheckers()) { RunPathSensitiveChecks(D,