Skip to content

Commit 2c5b872

Browse files
authored
Fix #14206 --showtime does not account for addons (#7904)
1 parent 554b98a commit 2c5b872

19 files changed

+151
-138
lines changed

Makefile

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -688,7 +688,7 @@ frontend/frontend.o: frontend/frontend.cpp frontend/frontend.h lib/addoninfo.h l
688688
cli/cmdlineparser.o: cli/cmdlineparser.cpp cli/cmdlinelogger.h cli/cmdlineparser.h cli/filelister.h externals/tinyxml2/tinyxml2.h lib/addoninfo.h lib/check.h lib/checkers.h lib/color.h lib/config.h lib/cppcheck.h lib/errorlogger.h lib/errortypes.h lib/filesettings.h lib/importproject.h lib/library.h lib/mathlib.h lib/path.h lib/pathmatch.h lib/platform.h lib/regex.h lib/settings.h lib/standards.h lib/suppressions.h lib/timer.h lib/utils.h lib/xml.h
689689
$(CXX) ${INCLUDE_FOR_CLI} $(CPPFLAGS) $(CXXFLAGS) -c -o $@ cli/cmdlineparser.cpp
690690

691-
cli/cppcheckexecutor.o: cli/cppcheckexecutor.cpp cli/cmdlinelogger.h cli/cmdlineparser.h cli/cppcheckexecutor.h cli/executor.h cli/processexecutor.h cli/sehwrapper.h cli/signalhandler.h cli/singleexecutor.h cli/threadexecutor.h externals/picojson/picojson.h lib/addoninfo.h lib/analyzerinfo.h lib/check.h lib/checkers.h lib/checkersreport.h lib/color.h lib/config.h lib/cppcheck.h lib/errorlogger.h lib/errortypes.h lib/filesettings.h lib/json.h lib/library.h lib/mathlib.h lib/path.h lib/platform.h lib/sarifreport.h lib/settings.h lib/standards.h lib/suppressions.h lib/utils.h
691+
cli/cppcheckexecutor.o: cli/cppcheckexecutor.cpp cli/cmdlinelogger.h cli/cmdlineparser.h cli/cppcheckexecutor.h cli/executor.h cli/processexecutor.h cli/sehwrapper.h cli/signalhandler.h cli/singleexecutor.h cli/threadexecutor.h externals/picojson/picojson.h lib/addoninfo.h lib/analyzerinfo.h lib/check.h lib/checkers.h lib/checkersreport.h lib/color.h lib/config.h lib/cppcheck.h lib/errorlogger.h lib/errortypes.h lib/filesettings.h lib/json.h lib/library.h lib/mathlib.h lib/path.h lib/platform.h lib/sarifreport.h lib/settings.h lib/standards.h lib/suppressions.h lib/timer.h lib/utils.h
692692
$(CXX) ${INCLUDE_FOR_CLI} $(CPPFLAGS) $(CXXFLAGS) -c -o $@ cli/cppcheckexecutor.cpp
693693

694694
cli/executor.o: cli/executor.cpp cli/executor.h lib/addoninfo.h lib/checkers.h lib/color.h lib/config.h lib/errorlogger.h lib/errortypes.h lib/library.h lib/mathlib.h lib/platform.h lib/settings.h lib/standards.h lib/suppressions.h lib/utils.h

cli/cmdlineparser.cpp

Lines changed: 6 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -1409,17 +1409,17 @@ CmdLineParser::Result CmdLineParser::parseFromArgs(int argc, const char* const a
14091409
else if (std::strncmp(argv[i], "--showtime=", 11) == 0) {
14101410
const std::string showtimeMode = argv[i] + 11;
14111411
if (showtimeMode == "file")
1412-
mSettings.showtime = SHOWTIME_MODES::SHOWTIME_FILE;
1412+
mSettings.showtime = ShowTime::FILE;
14131413
else if (showtimeMode == "file-total")
1414-
mSettings.showtime = SHOWTIME_MODES::SHOWTIME_FILE_TOTAL;
1414+
mSettings.showtime = ShowTime::FILE_TOTAL;
14151415
else if (showtimeMode == "summary")
1416-
mSettings.showtime = SHOWTIME_MODES::SHOWTIME_SUMMARY;
1416+
mSettings.showtime = ShowTime::SUMMARY;
14171417
else if (showtimeMode == "top5_file")
1418-
mSettings.showtime = SHOWTIME_MODES::SHOWTIME_TOP5_FILE;
1418+
mSettings.showtime = ShowTime::TOP5_FILE;
14191419
else if (showtimeMode == "top5_summary")
1420-
mSettings.showtime = SHOWTIME_MODES::SHOWTIME_TOP5_SUMMARY;
1420+
mSettings.showtime = ShowTime::TOP5_SUMMARY;
14211421
else if (showtimeMode == "none")
1422-
mSettings.showtime = SHOWTIME_MODES::SHOWTIME_NONE;
1422+
mSettings.showtime = ShowTime::NONE;
14231423
else if (showtimeMode.empty()) {
14241424
mLogger.printError("no mode provided for --showtime");
14251425
return Result::Fail;

cli/cppcheckexecutor.cpp

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -38,6 +38,7 @@
3838
#include "settings.h"
3939
#include "singleexecutor.h"
4040
#include "suppressions.h"
41+
#include "timer.h"
4142
#include "utils.h"
4243

4344
#if defined(HAS_THREADING_MODEL_THREAD)
@@ -270,6 +271,8 @@ int CppCheckExecutor::check(int argc, const char* const argv[])
270271
return EXIT_SUCCESS;
271272
}
272273

274+
Timer realTimeClock("", settings.showtime, nullptr, Timer::Type::OVERALL);
275+
273276
settings.loadSummaries();
274277

275278
mFiles = parser.getFiles();

cli/processexecutor.cpp

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -450,7 +450,7 @@ unsigned int ProcessExecutor::check()
450450
}
451451

452452
// TODO: wee need to get the timing information from the subprocess
453-
if (mSettings.showtime == SHOWTIME_MODES::SHOWTIME_SUMMARY || mSettings.showtime == SHOWTIME_MODES::SHOWTIME_TOP5_SUMMARY)
453+
if (mSettings.showtime == ShowTime::SUMMARY || mSettings.showtime == ShowTime::TOP5_SUMMARY)
454454
CppCheck::printTimerResults(mSettings.showtime);
455455

456456
return result;

cli/singleexecutor.cpp

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -70,7 +70,7 @@ unsigned int SingleExecutor::check()
7070
if (mCppcheck.analyseWholeProgram())
7171
result++;
7272

73-
if (mSettings.showtime == SHOWTIME_MODES::SHOWTIME_SUMMARY || mSettings.showtime == SHOWTIME_MODES::SHOWTIME_TOP5_SUMMARY)
73+
if (mSettings.showtime == ShowTime::SUMMARY || mSettings.showtime == ShowTime::TOP5_SUMMARY)
7474
CppCheck::printTimerResults(mSettings.showtime);
7575

7676
return result;

cli/threadexecutor.cpp

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -214,7 +214,7 @@ unsigned int ThreadExecutor::check()
214214
return v + f.get();
215215
});
216216

217-
if (mSettings.showtime == SHOWTIME_MODES::SHOWTIME_SUMMARY || mSettings.showtime == SHOWTIME_MODES::SHOWTIME_TOP5_SUMMARY)
217+
if (mSettings.showtime == ShowTime::SUMMARY || mSettings.showtime == ShowTime::TOP5_SUMMARY)
218218
CppCheck::printTimerResults(mSettings.showtime);
219219

220220
return result;

lib/cppcheck.cpp

Lines changed: 7 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -910,7 +910,7 @@ unsigned int CppCheck::checkInternal(const FileWithDetails& file, const std::str
910910
if (Settings::terminated())
911911
return mLogger->exitcode();
912912

913-
const Timer fileTotalTimer(mSettings.showtime == SHOWTIME_MODES::SHOWTIME_FILE_TOTAL, file.spath());
913+
const Timer fileTotalTimer{file.spath(), mSettings.showtime, nullptr, Timer::Type::FILE};
914914

915915
if (!mSettings.quiet) {
916916
std::string fixedpath = Path::toNativeSeparators(file.spath());
@@ -1161,7 +1161,7 @@ unsigned int CppCheck::checkInternal(const FileWithDetails& file, const std::str
11611161

11621162
Tokenizer tokenizer(std::move(tokenlist), mErrorLogger);
11631163
try {
1164-
if (mSettings.showtime != SHOWTIME_MODES::SHOWTIME_NONE)
1164+
if (mSettings.showtime != ShowTime::NONE)
11651165
tokenizer.setTimerResults(&s_timerResults);
11661166
tokenizer.setDirectives(directives); // TODO: how to avoid repeated copies?
11671167

@@ -1307,7 +1307,7 @@ unsigned int CppCheck::checkInternal(const FileWithDetails& file, const std::str
13071307
// TODO: clear earlier?
13081308
mLogger->clear();
13091309

1310-
if (mSettings.showtime == SHOWTIME_MODES::SHOWTIME_FILE || mSettings.showtime == SHOWTIME_MODES::SHOWTIME_TOP5_FILE)
1310+
if (mSettings.showtime == ShowTime::FILE || mSettings.showtime == ShowTime::TOP5_FILE)
13111311
printTimerResults(mSettings.showtime);
13121312

13131313
return mLogger->exitcode();
@@ -1501,7 +1501,9 @@ void CppCheck::executeAddons(const std::string& dumpFile, const FileWithDetails&
15011501
{
15021502
if (!dumpFile.empty()) {
15031503
std::vector<std::string> f{dumpFile};
1504-
executeAddons(f, file.spath());
1504+
Timer::run("CppCheck::executeAddons", mSettings.showtime, &s_timerResults, [&]() {
1505+
executeAddons(f, file.spath());
1506+
});
15051507
}
15061508
}
15071509

@@ -1933,7 +1935,7 @@ void CppCheck::resetTimerResults()
19331935
s_timerResults.reset();
19341936
}
19351937

1936-
void CppCheck::printTimerResults(SHOWTIME_MODES mode)
1938+
void CppCheck::printTimerResults(ShowTime mode)
19371939
{
19381940
s_timerResults.showResults(mode);
19391941
}

lib/cppcheck.h

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -33,7 +33,7 @@
3333
#include <vector>
3434

3535
class TokenList;
36-
enum class SHOWTIME_MODES : std::uint8_t;
36+
enum class ShowTime : std::uint8_t;
3737
struct FileSettings;
3838
class CheckUnusedFunctions;
3939
class Tokenizer;
@@ -143,7 +143,7 @@ class CPPCHECKLIB CppCheck {
143143
unsigned int analyseWholeProgram(const std::string &buildDir, const std::list<FileWithDetails> &files, const std::list<FileSettings>& fileSettings, const std::string& ctuInfo);
144144

145145
static void resetTimerResults();
146-
static void printTimerResults(SHOWTIME_MODES mode);
146+
static void printTimerResults(ShowTime mode);
147147

148148
private:
149149
void purgedConfigurationMessage(const std::string &file, const std::string& configuration);

lib/settings.h

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -51,7 +51,7 @@ class Regex;
5151
#endif
5252

5353
struct Suppressions;
54-
enum class SHOWTIME_MODES : std::uint8_t;
54+
enum class ShowTime : std::uint8_t;
5555
namespace ValueFlow {
5656
class Value;
5757
}
@@ -416,7 +416,7 @@ class CPPCHECKLIB WARN_UNUSED Settings {
416416
SimpleEnableGroup<Checks> checks;
417417

418418
/** @brief show timing information (--showtime=file|summary|top5) */
419-
SHOWTIME_MODES showtime{};
419+
ShowTime showtime{};
420420

421421
/** Struct contains standards settings */
422422
Standards standards;

lib/timer.cpp

Lines changed: 53 additions & 52 deletions
Original file line numberDiff line numberDiff line change
@@ -29,7 +29,7 @@ namespace {
2929
using dataElementType = std::pair<std::string, TimerResultsData>;
3030
bool more_second_sec(const dataElementType& lhs, const dataElementType& rhs)
3131
{
32-
return lhs.second.seconds() > rhs.second.seconds();
32+
return lhs.second.getSeconds() > rhs.second.getSeconds();
3333
}
3434

3535
// TODO: remove and print through (synchronized) ErrorLogger instead
@@ -38,12 +38,10 @@ namespace {
3838

3939
// TODO: this does not include any file context when SHOWTIME_FILE thus rendering it useless - should we include the logging with the progress logging?
4040
// that could also get rid of the broader locking
41-
void TimerResults::showResults(SHOWTIME_MODES mode) const
41+
void TimerResults::showResults(ShowTime mode) const
4242
{
43-
if (mode == SHOWTIME_MODES::SHOWTIME_NONE || mode == SHOWTIME_MODES::SHOWTIME_FILE_TOTAL)
43+
if (mode == ShowTime::NONE || mode == ShowTime::FILE_TOTAL)
4444
return;
45-
46-
TimerResultsData overallData;
4745
std::vector<dataElementType> data;
4846

4947
{
@@ -61,38 +59,20 @@ void TimerResults::showResults(SHOWTIME_MODES mode) const
6159

6260
size_t ordinal = 1; // maybe it would be nice to have an ordinal in output later!
6361
for (auto iter=data.cbegin(); iter!=data.cend(); ++iter) {
64-
const double sec = iter->second.seconds();
62+
const double sec = iter->second.getSeconds().count();
6563
const double secAverage = sec / static_cast<double>(iter->second.mNumberOfResults);
66-
bool hasParent = false;
67-
{
68-
// Do not use valueFlow.. in "Overall time" because those are included in Tokenizer already
69-
if (startsWith(iter->first,"valueFlow"))
70-
hasParent = true;
71-
72-
// Do not use inner timers in "Overall time"
73-
const std::string::size_type pos = iter->first.rfind("::");
74-
if (pos != std::string::npos)
75-
hasParent = std::any_of(data.cbegin(), data.cend(), [iter,pos](const dataElementType& d) {
76-
return d.first.size() == pos && iter->first.compare(0, d.first.size(), d.first) == 0;
77-
});
78-
}
79-
if (!hasParent)
80-
overallData.mClocks += iter->second.mClocks;
81-
if ((mode != SHOWTIME_MODES::SHOWTIME_TOP5_FILE && mode != SHOWTIME_MODES::SHOWTIME_TOP5_SUMMARY) || (ordinal<=5)) {
64+
if ((mode != ShowTime::TOP5_FILE && mode != ShowTime::TOP5_SUMMARY) || (ordinal<=5)) {
8265
std::cout << iter->first << ": " << sec << "s (avg. " << secAverage << "s - " << iter->second.mNumberOfResults << " result(s))" << std::endl;
8366
}
8467
++ordinal;
8568
}
86-
87-
const double secOverall = overallData.seconds();
88-
std::cout << "Overall time: " << secOverall << "s" << std::endl;
8969
}
9070

91-
void TimerResults::addResults(const std::string& str, std::clock_t clocks)
71+
void TimerResults::addResults(const std::string& str, std::chrono::milliseconds duration)
9272
{
9373
std::lock_guard<std::mutex> l(mResultsSync);
9474

95-
mResults[str].mClocks += clocks;
75+
mResults[str].mDuration += duration;
9676
mResults[str].mNumberOfResults++;
9777
}
9878

@@ -102,17 +82,12 @@ void TimerResults::reset()
10282
mResults.clear();
10383
}
10484

105-
Timer::Timer(std::string str, SHOWTIME_MODES showtimeMode, TimerResultsIntf* timerResults)
106-
: mStr(std::move(str))
107-
, mTimerResults(timerResults)
108-
, mStart(std::clock())
109-
, mShowTimeMode(showtimeMode)
110-
, mStopped(showtimeMode == SHOWTIME_MODES::SHOWTIME_NONE || showtimeMode == SHOWTIME_MODES::SHOWTIME_FILE_TOTAL)
111-
{}
112-
113-
Timer::Timer(bool fileTotal, std::string filename)
114-
: mStr(std::move(filename))
115-
, mStopped(!fileTotal)
85+
Timer::Timer(std::string str, ShowTime showtimeMode, TimerResultsIntf* timerResults, Type type)
86+
: mName(std::move(str))
87+
, mMode(showtimeMode)
88+
, mType(type)
89+
, mStart(Clock::now())
90+
, mResults(timerResults)
11691
{}
11792

11893
Timer::~Timer()
@@ -122,23 +97,49 @@ Timer::~Timer()
12297

12398
void Timer::stop()
12499
{
125-
if ((mShowTimeMode != SHOWTIME_MODES::SHOWTIME_NONE) && !mStopped) {
126-
const std::clock_t end = std::clock();
127-
const std::clock_t diff = end - mStart;
128-
129-
if (mShowTimeMode == SHOWTIME_MODES::SHOWTIME_FILE) {
130-
const double sec = static_cast<double>(diff) / CLOCKS_PER_SEC;
131-
std::lock_guard<std::mutex> l(stdCoutLock);
132-
std::cout << mStr << ": " << sec << "s" << std::endl;
133-
} else if (mShowTimeMode == SHOWTIME_MODES::SHOWTIME_FILE_TOTAL) {
134-
const double sec = static_cast<double>(diff) / CLOCKS_PER_SEC;
100+
if (mMode == ShowTime::NONE)
101+
return;
102+
if (mType == Type::OVERALL && mMode != ShowTime::TOP5_SUMMARY && mMode != ShowTime::SUMMARY) {
103+
mMode = ShowTime::NONE;
104+
return;
105+
}
106+
if (mType == Type::FILE && mMode != ShowTime::TOP5_FILE && mMode != ShowTime::FILE && mMode != ShowTime::FILE_TOTAL) {
107+
mMode = ShowTime::NONE;
108+
return;
109+
}
110+
if (mStart != TimePoint{}) {
111+
auto diff = std::chrono::duration_cast<std::chrono::milliseconds>(Clock::now() - mStart);
112+
if (!mResults) {
135113
std::lock_guard<std::mutex> l(stdCoutLock);
136-
std::cout << "Check time: " << mStr << ": " << sec << "s" << std::endl;
114+
std::cout << (mType == Type::OVERALL ? "Overall time: " : "Check time: " + mName + ": ") << TimerResultsData::durationToString(diff) << std::endl;
137115
} else {
138-
if (mTimerResults)
139-
mTimerResults->addResults(mStr, diff);
116+
mResults->addResults(mName, diff);
140117
}
141118
}
119+
mMode = ShowTime::NONE; // prevent multiple stops
120+
}
142121

143-
mStopped = true;
122+
std::string TimerResultsData::durationToString(std::chrono::milliseconds duration)
123+
{
124+
// Extract hours
125+
auto hours = std::chrono::duration_cast<std::chrono::hours>(duration);
126+
duration -= hours; // Subtract the extracted hours
127+
128+
// Extract minutes
129+
auto minutes = std::chrono::duration_cast<std::chrono::minutes>(duration);
130+
duration -= minutes; // Subtract the extracted minutes
131+
132+
// Extract seconds
133+
std::chrono::duration<double> seconds = std::chrono::duration_cast<std::chrono::duration<double>>(duration);
134+
135+
std::string ellapsedTime;
136+
if (hours.count() > 0)
137+
ellapsedTime += std::to_string(hours.count()) + "h ";
138+
if (minutes.count() > 0)
139+
ellapsedTime += std::to_string(minutes.count()) + "m ";
140+
std::string secondsStr{std::to_string(seconds.count())};
141+
auto pos = secondsStr.find_first_of('.');
142+
if (pos != std::string::npos && (pos + 4) < secondsStr.size())
143+
secondsStr.resize(pos + 4); // keep three decimal
144+
return (ellapsedTime + secondsStr + "s");
144145
}

0 commit comments

Comments
 (0)