diff --git a/src/gtest/test_metrics.cpp b/src/gtest/test_metrics.cpp index 33c33d4d4..c199b323e 100644 --- a/src/gtest/test_metrics.cpp +++ b/src/gtest/test_metrics.cpp @@ -4,9 +4,57 @@ #include "utiltime.h" +TEST(Metrics, AtomicTimer) { + AtomicTimer t; + SetMockTime(100); + + EXPECT_FALSE(t.running()); + + t.start(); + EXPECT_TRUE(t.running()); + + t.start(); + EXPECT_TRUE(t.running()); + + t.stop(); + EXPECT_TRUE(t.running()); + + t.stop(); + EXPECT_FALSE(t.running()); + + // Additional calls to stop() are ignored. + t.stop(); + EXPECT_FALSE(t.running()); + + t.start(); + EXPECT_TRUE(t.running()); + + AtomicCounter c; + EXPECT_EQ(0, t.rate(c)); + + c.increment(); + EXPECT_EQ(0, t.rate(c)); + + SetMockTime(101); + EXPECT_EQ(1, t.rate(c)); + + c.decrement(); + EXPECT_EQ(0, t.rate(c)); + + SetMockTime(102); + EXPECT_EQ(0, t.rate(c)); + + c.increment(); + EXPECT_EQ(0.5, t.rate(c)); + + t.stop(); + EXPECT_FALSE(t.running()); + EXPECT_EQ(0.5, t.rate(c)); +} + TEST(Metrics, GetLocalSolPS) { SetMockTime(100); - MarkStartTime(); + miningTimer.start(); // No time has passed EXPECT_EQ(0, GetLocalSolPS()); @@ -27,4 +75,20 @@ TEST(Metrics, GetLocalSolPS) { solutionTargetChecks.increment(); solutionTargetChecks.increment(); EXPECT_EQ(1.5, GetLocalSolPS()); + + // Stop timing + miningTimer.stop(); + EXPECT_EQ(1.5, GetLocalSolPS()); + + // Increment time + SetMockTime(103); + EXPECT_EQ(1.5, GetLocalSolPS()); + + // Start timing again + miningTimer.start(); + EXPECT_EQ(1.5, GetLocalSolPS()); + + // Increment time + SetMockTime(104); + EXPECT_EQ(1, GetLocalSolPS()); } diff --git a/src/metrics.cpp b/src/metrics.cpp index b63fd16ea..fe2c57081 100644 --- a/src/metrics.cpp +++ b/src/metrics.cpp @@ -17,6 +17,45 @@ #include #include +void AtomicTimer::start() +{ + std::unique_lock lock(mtx); + if (threads < 1) { + start_time = GetTime(); + } + ++threads; +} + +void AtomicTimer::stop() +{ + std::unique_lock lock(mtx); + // Ignore excess calls to stop() + if (threads > 0) { + --threads; + if (threads < 1) { + int64_t time_span = GetTime() - start_time; + total_time += time_span; + } + } +} + +bool AtomicTimer::running() +{ + std::unique_lock lock(mtx); + return threads > 0; +} + +double AtomicTimer::rate(const AtomicCounter& count) +{ + std::unique_lock lock(mtx); + int64_t duration = total_time; + if (threads > 0) { + // Timer is running, so get the latest count + duration += GetTime() - start_time; + } + return duration > 0 ? (double)count.get() / duration : 0; +} + CCriticalSection cs_metrics; boost::synchronized_value nNodeStartTime; @@ -25,6 +64,7 @@ AtomicCounter transactionsValidated; AtomicCounter ehSolverRuns; AtomicCounter solutionTargetChecks; AtomicCounter minedBlocks; +AtomicTimer miningTimer; boost::synchronized_value> trackedBlocks; @@ -51,14 +91,9 @@ int64_t GetUptime() return GetTime() - *nNodeStartTime; } -double GetLocalSolPS_INTERNAL(int64_t uptime) -{ - return uptime > 0 ? (double)solutionTargetChecks.get() / uptime : 0; -} - double GetLocalSolPS() { - return GetLocalSolPS_INTERNAL(GetUptime()); + return miningTimer.rate(solutionTargetChecks); } void TriggerRefresh() @@ -121,16 +156,32 @@ void ConnectMetricsScreen() uiInterface.InitMessage.connect(metrics_InitMessage); } -int printNetworkStats() +int printStats(bool mining) { - LOCK2(cs_main, cs_vNodes); + // Number of lines that are always displayed + int lines = 4; - std::cout << " " << _("Block height") << " | " << chainActive.Height() << std::endl; - std::cout << " " << _("Network solution rate") << " | " << GetNetworkHashPS(120, -1) << " Sol/s" << std::endl; - std::cout << " " << _("Connections") << " | " << vNodes.size() << std::endl; + int height; + size_t connections; + int64_t netsolps; + { + LOCK2(cs_main, cs_vNodes); + height = chainActive.Height(); + connections = vNodes.size(); + netsolps = GetNetworkHashPS(120, -1); + } + auto localsolps = GetLocalSolPS(); + + std::cout << " " << _("Block height") << " | " << height << std::endl; + std::cout << " " << _("Connections") << " | " << connections << std::endl; + std::cout << " " << _("Network solution rate") << " | " << netsolps << " Sol/s" << std::endl; + if (mining && miningTimer.running()) { + std::cout << " " << _("Local solution rate") << " | " << strprintf("%.4f Sol/s", localsolps) << std::endl; + lines++; + } std::cout << std::endl; - return 4; + return lines; } int printMiningStatus(bool mining) @@ -148,8 +199,23 @@ int printMiningStatus(bool mining) else nThreads = boost::thread::hardware_concurrency(); } - std::cout << strprintf(_("You are mining with the %s solver on %d threads."), - GetArg("-equihashsolver", "default"), nThreads) << std::endl; + if (miningTimer.running()) { + std::cout << strprintf(_("You are mining with the %s solver on %d threads."), + GetArg("-equihashsolver", "default"), nThreads) << std::endl; + } else { + bool fvNodesEmpty; + { + LOCK(cs_vNodes); + fvNodesEmpty = vNodes.empty(); + } + if (fvNodesEmpty) { + std::cout << _("Mining is paused while waiting for connections.") << std::endl; + } else if (IsInitialBlockDownload()) { + std::cout << _("Mining is paused while downloading blocks.") << std::endl; + } else { + std::cout << _("Mining is paused (a JoinSplit may be in progress).") << std::endl; + } + } lines++; } else { std::cout << _("You are currently not mining.") << std::endl; @@ -201,11 +267,8 @@ int printMetrics(size_t cols, bool mining) } if (mining && loaded) { - double solps = GetLocalSolPS_INTERNAL(uptime); - std::string strSolps = strprintf("%.4f Sol/s", solps); - std::cout << "- " << strprintf(_("You have contributed %s on average to the network solution rate."), strSolps) << std::endl; std::cout << "- " << strprintf(_("You have completed %d Equihash solver runs."), ehSolverRuns.get()) << std::endl; - lines += 2; + lines++; int mined = 0; int orphaned = 0; @@ -360,9 +423,9 @@ void ThreadShowMetricsScreen() #endif if (loaded) { - lines += printNetworkStats(); + lines += printStats(mining); + lines += printMiningStatus(mining); } - lines += printMiningStatus(mining); lines += printMetrics(cols, mining); lines += printMessageBox(cols); lines += printInitMessage(); diff --git a/src/metrics.h b/src/metrics.h index 57264a7b5..3e830f823 100644 --- a/src/metrics.h +++ b/src/metrics.h @@ -5,6 +5,7 @@ #include "uint256.h" #include +#include #include struct AtomicCounter { @@ -20,14 +21,41 @@ struct AtomicCounter { --value; } - int get(){ + int get() const { return value.load(); } }; +class AtomicTimer { +private: + std::mutex mtx; + uint64_t threads; + int64_t start_time; + int64_t total_time; + +public: + AtomicTimer() : threads(0), start_time(0), total_time(0) {} + + /** + * Starts timing on first call, and counts the number of calls. + */ + void start(); + + /** + * Counts number of calls, and stops timing after it has been called as + * many times as start(). + */ + void stop(); + + bool running(); + + double rate(const AtomicCounter& count); +}; + extern AtomicCounter transactionsValidated; extern AtomicCounter ehSolverRuns; extern AtomicCounter solutionTargetChecks; +extern AtomicTimer miningTimer; void TrackMinedBlock(uint256 hash); diff --git a/src/miner.cpp b/src/miner.cpp index 5e2811504..6d34a1a9f 100644 --- a/src/miner.cpp +++ b/src/miner.cpp @@ -528,12 +528,14 @@ void static BitcoinMiner() cancelSolver = true; } ); + miningTimer.start(); try { while (true) { if (chainparams.MiningRequiresPeers()) { // Busy-wait for the network to come online so we don't waste time mining // on an obsolete chain. In regtest mode we expect to fly solo. + miningTimer.stop(); do { bool fvNodesEmpty; { @@ -544,6 +546,7 @@ void static BitcoinMiner() break; MilliSleep(1000); } while (true); + miningTimer.start(); } // @@ -721,16 +724,19 @@ void static BitcoinMiner() } catch (const boost::thread_interrupted&) { + miningTimer.stop(); c.disconnect(); LogPrintf("ZcashMiner terminated\n"); throw; } catch (const std::runtime_error &e) { + miningTimer.stop(); c.disconnect(); LogPrintf("ZcashMiner runtime error: %s\n", e.what()); return; } + miningTimer.stop(); c.disconnect(); }