fixed #14618 - added more metrics to timer summary / small TimerResultsData refactoring

cli/cppcheckexecutor.cpp

@@ -267,8 +267,9 @@ int CppCheckExecutor::check(int argc, const char* const argv[])
         return EXIT_SUCCESS;
     }
 
-    TimerResults overallTimerResults;
-    Timer realTimeClock("Overall time", settings.showtime, &overallTimerResults, Timer::Type::OVERALL);
+    std::unique_ptr<OneShotTimer> overallTimer;
+    if (settings.showtime == ShowTime::SUMMARY || settings.showtime == ShowTime::TOP5_SUMMARY)
+        overallTimer.reset(new OneShotTimer("Overall time", settings.showtime));
 
     settings.loadSummaries();
 
@@ -277,9 +278,6 @@ int CppCheckExecutor::check(int argc, const char* const argv[])
 
     const int ret = check_wrapper(settings, supprs);
 
-    realTimeClock.stop();
-    overallTimerResults.showResults(settings.showtime, false, true);
-
     return ret;
 }
 

lib/cppcheck.cpp

@@ -923,8 +923,9 @@ unsigned int CppCheck::checkInternal(const FileWithDetails& file, const std::str
     if (Settings::terminated())
         return mLogger->exitcode();
 
-    TimerResults checkTimeResults;
-    Timer fileTotalTimer{"Check time: " + file.spath(), mSettings.showtime, &checkTimeResults, Timer::Type::FILE};
+    std::unique_ptr<OneShotTimer> checkTimeTimer;
+    if (mSettings.showtime == ShowTime::FILE || mSettings.showtime == ShowTime::FILE_TOTAL || mSettings.showtime == ShowTime::TOP5_FILE)
+        checkTimeTimer.reset(new OneShotTimer("Check time: " + file.spath(), mSettings.showtime));
 
     if (!mSettings.quiet) {
         std::string fixedpath = Path::toNativeSeparators(file.spath());
@@ -1296,9 +1297,6 @@ unsigned int CppCheck::checkInternal(const FileWithDetails& file, const std::str
     if (mTimerResults && (mSettings.showtime == ShowTime::FILE || mSettings.showtime == ShowTime::TOP5_FILE))
         mTimerResults->showResults(mSettings.showtime);
 
-    fileTotalTimer.stop();
-    checkTimeResults.showResults(mSettings.showtime, false, true);
-
     return mLogger->exitcode();
 }
 

lib/timer.cpp

@@ -38,7 +38,7 @@ namespace {
 
 // TODO: this does not include any file context when SHOWTIME_FILE thus rendering it useless - should we include the logging with the progress logging?
 // that could also get rid of the broader locking
-void TimerResults::showResults(ShowTime mode, bool metrics, bool format) const
+void TimerResults::showResults(ShowTime mode, bool metrics) const
 {
     if (mode == ShowTime::NONE)
         return;
@@ -57,28 +57,26 @@ void TimerResults::showResults(ShowTime mode, bool metrics, bool format) const
 
     size_t ordinal = 1; // maybe it would be nice to have an ordinal in output later!
     for (auto iter=data.cbegin(); iter!=data.cend(); ++iter) {
-        const double sec = iter->second.getSeconds().count();
-        const double secAverage = sec / static_cast<double>(iter->second.mNumberOfResults);
         if ((mode != ShowTime::TOP5_FILE && mode != ShowTime::TOP5_SUMMARY) || (ordinal<=5)) {
-            std::cout << iter->first << ": ";
-            if (format)
-                std::cout << TimerResultsData::durationToString(iter->second.mDuration);
-            else
-                std::cout << sec << "s";
-            if (metrics)
-                std::cout << " (avg. " << secAverage << "s - " << iter->second.mNumberOfResults  << " result(s))";
+            const double sec = iter->second.getSeconds().count();
+            std::cout << iter->first << ": " << sec << "s";
+            if (metrics) {
+                const double secAverage = sec / static_cast<double>(iter->second.mResults.size());
+                const double secMin = asSeconds(*std::min_element(iter->second.mResults.cbegin(), iter->second.mResults.cend())).count();
+                const double secMax = asSeconds(*std::max_element(iter->second.mResults.cbegin(), iter->second.mResults.cend())).count();
+                std::cout << " (avg. " << secAverage << "s / min " << secMin << "s / max " << secMax << "s - " << iter->second.mResults.size() << " result(s))";
+            }
             std::cout << std::endl;
         }
         ++ordinal;
     }
 }
 
-void TimerResults::addResults(const std::string& str, std::chrono::milliseconds duration)
+void TimerResults::addResults(const std::string& name, std::chrono::milliseconds duration)
 {
     std::lock_guard<std::mutex> l(mResultsSync);
 
-    mResults[str].mDuration += duration;
-    mResults[str].mNumberOfResults++;
+    mResults[name].mResults.push_back(duration);
 }
 
 void TimerResults::reset()
@@ -87,10 +85,9 @@ void TimerResults::reset()
     mResults.clear();
 }
 
-Timer::Timer(std::string str, ShowTime showtimeMode, TimerResultsIntf* timerResults, Type type)
+Timer::Timer(std::string str, ShowTime showtimeMode, TimerResultsIntf* timerResults)
     : mName(std::move(str))
     , mMode(showtimeMode)
-    , mType(type)
     , mStart(Clock::now())
     , mResults(timerResults)
 {}
@@ -104,14 +101,6 @@ void Timer::stop()
 {
     if (mMode == ShowTime::NONE)
         return;
-    if (mType == Type::OVERALL && mMode != ShowTime::TOP5_SUMMARY && mMode != ShowTime::SUMMARY) {
-        mMode = ShowTime::NONE;
-        return;
-    }
-    if (mType == Type::FILE && mMode != ShowTime::TOP5_FILE && mMode != ShowTime::FILE && mMode != ShowTime::FILE_TOTAL) {
-        mMode = ShowTime::NONE;
-        return;
-    }
     if (mStart != TimePoint{}) {
         if (!mResults) {
             assert(false);
@@ -124,7 +113,7 @@ void Timer::stop()
     mMode = ShowTime::NONE; // prevent multiple stops
 }
 
-std::string TimerResultsData::durationToString(std::chrono::milliseconds duration)
+static std::string durationToString(std::chrono::milliseconds duration)
 {
     // Extract hours
     auto hours = std::chrono::duration_cast<std::chrono::hours>(duration);
@@ -148,3 +137,24 @@ std::string TimerResultsData::durationToString(std::chrono::milliseconds duratio
         secondsStr.resize(pos + 4); // keep three decimal
     return (ellapsedTime + secondsStr + "s");
 }
+
+OneShotTimer::OneShotTimer(std::string name, ShowTime showtime)
+{
+    if (showtime == ShowTime::NONE)
+        return;
+
+    class MyResults : public TimerResultsIntf
+    {
+    private:
+        void addResults(const std::string &name, std::chrono::milliseconds duration) override
+        {
+            std::lock_guard<std::mutex> l(stdCoutLock);
+
+            // TODO: do not use std::cout directly
+            std::cout << name << ": " << durationToString(duration) << std::endl;
+        }
+    };
+
+    mResults.reset(new MyResults);
+    mTimer.reset(new Timer(std::move(name), showtime, mResults.get()));
+}

lib/timer.h

@@ -25,9 +25,12 @@
 #include <chrono>
 #include <cstdint>
 #include <map>
+#include <memory>
 #include <mutex>
+#include <numeric>
 #include <string>
 #include <utility>
+#include <vector>
 
 enum class ShowTime : std::uint8_t {
     NONE,
@@ -42,26 +45,29 @@ class CPPCHECKLIB TimerResultsIntf {
 public:
     virtual ~TimerResultsIntf() = default;
 
-    virtual void addResults(const std::string& timerName, std::chrono::milliseconds duation) = 0;
+    virtual void addResults(const std::string& name, std::chrono::milliseconds duration) = 0;
+
+    static std::chrono::duration<double> asSeconds(std::chrono::milliseconds ms) {
+        return std::chrono::duration_cast<std::chrono::duration<double>>(ms);
+    }
 };
 
 struct TimerResultsData {
-    std::chrono::milliseconds mDuration;
-    long mNumberOfResults{};
+    std::vector<std::chrono::milliseconds> mResults;
 
     std::chrono::duration<double> getSeconds() const {
-        return std::chrono::duration_cast<std::chrono::duration<double>>(mDuration);
+        return std::accumulate(mResults.cbegin(), mResults.cend(), std::chrono::duration<double>{}, [](std::chrono::duration<double> secs, std::chrono::milliseconds duration) {
+            return secs + TimerResultsIntf::asSeconds(duration);
+        });
     }
-
-    static std::string durationToString(std::chrono::milliseconds duration);
 };
 
 class CPPCHECKLIB WARN_UNUSED TimerResults : public TimerResultsIntf {
 public:
     TimerResults() = default;
 
-    void showResults(ShowTime mode, bool metrics = true, bool format = false) const;
-    void addResults(const std::string& str, std::chrono::milliseconds duration) override;
+    void showResults(ShowTime mode, bool metrics = true) const;
+    void addResults(const std::string& name, std::chrono::milliseconds duration) override;
 
     void reset();
 
@@ -75,13 +81,7 @@ class CPPCHECKLIB Timer {
     using Clock = std::chrono::high_resolution_clock;
     using TimePoint = std::chrono::time_point<Clock>;
 
-    enum class Type : std::uint8_t {
-        FILE,
-        OVERALL,
-        OTHER
-    };
-
-    Timer(std::string str, ShowTime showtimeMode, TimerResultsIntf* timerResults = nullptr, Type type = Type::OTHER);
+    Timer(std::string str, ShowTime showtimeMode, TimerResultsIntf* timerResults = nullptr);
     ~Timer();
 
     Timer(const Timer&) = delete;
@@ -98,10 +98,18 @@ class CPPCHECKLIB Timer {
 private:
     const std::string mName;
     ShowTime mMode{};
-    Type mType{};
     TimePoint mStart;
     TimerResultsIntf* mResults{};
 };
 
+class CPPCHECKLIB OneShotTimer
+{
+public:
+    OneShotTimer(std::string name, ShowTime showtime);
+private:
+    std::unique_ptr<TimerResultsIntf> mResults;
+    std::unique_ptr<Timer> mTimer;
+};
+
 //---------------------------------------------------------------------------
 #endif // timerH