From 73bf85b44f62a448af914e9cb15e0f458e9fedb1 Mon Sep 17 00:00:00 2001 From: Jack Grigg Date: Thu, 23 Mar 2017 12:35:44 +1300 Subject: [PATCH 1/7] Implement an AtomicTimer --- src/metrics.cpp | 39 +++++++++++++++++++++++++++++++++++++++ src/metrics.h | 29 ++++++++++++++++++++++++++++- 2 files changed, 67 insertions(+), 1 deletion(-) diff --git a/src/metrics.cpp b/src/metrics.cpp index b63fd16ea..f54d6e243 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; diff --git a/src/metrics.h b/src/metrics.h index 57264a7b5..ff1138b99 100644 --- a/src/metrics.h +++ b/src/metrics.h @@ -5,6 +5,7 @@ #include "uint256.h" #include +#include #include struct AtomicCounter { @@ -20,11 +21,37 @@ 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; From 07be8f7eb961173c221c332f3849a1985c29bdae Mon Sep 17 00:00:00 2001 From: Jack Grigg Date: Thu, 23 Mar 2017 12:37:22 +1300 Subject: [PATCH 2/7] Use AtomicTimer for more accurate local solution rate --- src/metrics.cpp | 10 +++------- src/metrics.h | 1 + src/miner.cpp | 6 ++++++ 3 files changed, 10 insertions(+), 7 deletions(-) diff --git a/src/metrics.cpp b/src/metrics.cpp index f54d6e243..7bd447af6 100644 --- a/src/metrics.cpp +++ b/src/metrics.cpp @@ -64,6 +64,7 @@ AtomicCounter transactionsValidated; AtomicCounter ehSolverRuns; AtomicCounter solutionTargetChecks; AtomicCounter minedBlocks; +AtomicTimer miningTimer; boost::synchronized_value> trackedBlocks; @@ -90,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() @@ -240,7 +236,7 @@ int printMetrics(size_t cols, bool mining) } if (mining && loaded) { - double solps = GetLocalSolPS_INTERNAL(uptime); + double solps = GetLocalSolPS(); 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; diff --git a/src/metrics.h b/src/metrics.h index ff1138b99..3e830f823 100644 --- a/src/metrics.h +++ b/src/metrics.h @@ -55,6 +55,7 @@ public: 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(); } From dd20d046791d213f67bb3bbe6fdb4d15af9dee06 Mon Sep 17 00:00:00 2001 From: Jack Grigg Date: Thu, 23 Mar 2017 14:04:12 +1300 Subject: [PATCH 3/7] Metrics: Move local solution rate into stats --- src/metrics.cpp | 35 ++++++++++++++++++++++++----------- 1 file changed, 24 insertions(+), 11 deletions(-) diff --git a/src/metrics.cpp b/src/metrics.cpp index 7bd447af6..464c79834 100644 --- a/src/metrics.cpp +++ b/src/metrics.cpp @@ -156,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) @@ -236,11 +252,8 @@ int printMetrics(size_t cols, bool mining) } if (mining && loaded) { - double solps = GetLocalSolPS(); - 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; @@ -395,7 +408,7 @@ void ThreadShowMetricsScreen() #endif if (loaded) { - lines += printNetworkStats(); + lines += printStats(mining); } lines += printMiningStatus(mining); lines += printMetrics(cols, mining); From af370021a09d28f87f6aa9419c0f09bfb8c91367 Mon Sep 17 00:00:00 2001 From: Jack Grigg Date: Thu, 23 Mar 2017 14:05:00 +1300 Subject: [PATCH 4/7] Metrics: Improve mining status --- src/metrics.cpp | 10 +++++++--- 1 file changed, 7 insertions(+), 3 deletions(-) diff --git a/src/metrics.cpp b/src/metrics.cpp index 464c79834..afae125dd 100644 --- a/src/metrics.cpp +++ b/src/metrics.cpp @@ -199,8 +199,12 @@ 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 { + std::cout << _("Mining is paused.") << std::endl; + } lines++; } else { std::cout << _("You are currently not mining.") << std::endl; @@ -409,8 +413,8 @@ void ThreadShowMetricsScreen() if (loaded) { lines += printStats(mining); + lines += printMiningStatus(mining); } - lines += printMiningStatus(mining); lines += printMetrics(cols, mining); lines += printMessageBox(cols); lines += printInitMessage(); From 493d8d81fb95482157175f5d5af0dd89e79bae37 Mon Sep 17 00:00:00 2001 From: Jack Grigg Date: Thu, 23 Mar 2017 15:16:04 +1300 Subject: [PATCH 5/7] Expand on reasons for mining being paused --- src/metrics.cpp | 13 ++++++++++++- 1 file changed, 12 insertions(+), 1 deletion(-) diff --git a/src/metrics.cpp b/src/metrics.cpp index afae125dd..fe2c57081 100644 --- a/src/metrics.cpp +++ b/src/metrics.cpp @@ -203,7 +203,18 @@ int printMiningStatus(bool mining) std::cout << strprintf(_("You are mining with the %s solver on %d threads."), GetArg("-equihashsolver", "default"), nThreads) << std::endl; } else { - std::cout << _("Mining is paused.") << std::endl; + 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 { From 5c0d105b6bdd3bd99d497c679954cefe002a10e5 Mon Sep 17 00:00:00 2001 From: Jack Grigg Date: Sat, 25 Mar 2017 12:56:31 +1300 Subject: [PATCH 6/7] Update LocalSolPS test --- src/gtest/test_metrics.cpp | 18 +++++++++++++++++- 1 file changed, 17 insertions(+), 1 deletion(-) diff --git a/src/gtest/test_metrics.cpp b/src/gtest/test_metrics.cpp index 33c33d4d4..8a5a1b5ce 100644 --- a/src/gtest/test_metrics.cpp +++ b/src/gtest/test_metrics.cpp @@ -6,7 +6,7 @@ TEST(Metrics, GetLocalSolPS) { SetMockTime(100); - MarkStartTime(); + miningTimer.start(); // No time has passed EXPECT_EQ(0, GetLocalSolPS()); @@ -27,4 +27,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()); } From 601f00f6fb13e8999ec92a948527fdde2eaf1276 Mon Sep 17 00:00:00 2001 From: Jack Grigg Date: Sat, 25 Mar 2017 13:06:00 +1300 Subject: [PATCH 7/7] Add AtomicTimer tests --- src/gtest/test_metrics.cpp | 48 ++++++++++++++++++++++++++++++++++++++ 1 file changed, 48 insertions(+) diff --git a/src/gtest/test_metrics.cpp b/src/gtest/test_metrics.cpp index 8a5a1b5ce..c199b323e 100644 --- a/src/gtest/test_metrics.cpp +++ b/src/gtest/test_metrics.cpp @@ -4,6 +4,54 @@ #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); miningTimer.start();