[CI] Adaptive mining timeout, depending on available CPU power

Printing also available RAM. Add comprehensive description.

6 files changed, 256 insertions, 12 deletions

diff --git a/.github/workflows/build.yml b/.github/workflows/build.yml
index 4c358e93e..a27996a50 100644
--- a/.github/workflows/build.yml
+++ b/.github/workflows/build.yml
@@ -130,8 +130,8 @@ jobs:
       run: sudo apt update
     - name: install monero dependencies
       run: sudo apt -y install build-essential cmake libboost-all-dev miniupnpc libunbound-dev graphviz doxygen libunwind8-dev pkg-config libssl-dev libzmq3-dev libsodium-dev libhidapi-dev libnorm-dev libusb-1.0-0-dev libpgm-dev libprotobuf-dev protobuf-compiler
-    - name: install requests
-      run: pip install requests
+    - name: install Python dependencies
+      run: pip install requests psutil monotonic
     - name: tests
       env:
         CTEST_OUTPUT_ON_FAILURE: ON
diff --git a/tests/README.md b/tests/README.md
index f6dd25ead..c4ad1ce37 100644
--- a/tests/README.md
+++ b/tests/README.md
@@ -52,6 +52,11 @@ To run the same tests on a release build, replace `debug` with `release`.
 [TODO]
 Functional tests are located under the `tests/functional` directory.
 
+Building all the tests requires installing the following dependencies:
+```bash
+pip install requests psutil monotonic
+```
+
 First, run a regtest daemon in the offline mode and with a fixed difficulty:
 ```bash
 monerod --regtest --offline --fixed-difficulty 1
diff --git a/tests/functional_tests/CMakeLists.txt b/tests/functional_tests/CMakeLists.txt
index 9f7024e36..337097a34 100644
--- a/tests/functional_tests/CMakeLists.txt
+++ b/tests/functional_tests/CMakeLists.txt
@@ -64,6 +64,7 @@ target_link_libraries(make_test_signature
     ${CMAKE_THREAD_LIBS_INIT}
     ${EXTRA_LIBRARIES})
 
+monero_add_minimal_executable(cpu_power_test cpu_power_test.cpp)
 find_program(PYTHON3_FOUND python3 REQUIRED)
 
 execute_process(COMMAND ${PYTHON3_FOUND} "-c" "import requests; import psutil; import monotonic; print('OK')" OUTPUT_VARIABLE REQUESTS_OUTPUT OUTPUT_STRIP_TRAILING_WHITESPACE)
diff --git a/tests/functional_tests/cpu_power_test.cpp b/tests/functional_tests/cpu_power_test.cpp
new file mode 100644
index 000000000..54c4bfc9f
--- /dev/null
+++ b/tests/functional_tests/cpu_power_test.cpp
@@ -0,0 +1,112 @@
+// Copyright (c) 2014-2021, The Monero Project
+// 
+// All rights reserved.
+// 
+// Redistribution and use in source and binary forms, with or without modification, are
+// permitted provided that the following conditions are met:
+// 
+// 1. Redistributions of source code must retain the above copyright notice, this list of
+//    conditions and the following disclaimer.
+// 
+// 2. Redistributions in binary form must reproduce the above copyright notice, this list
+//    of conditions and the following disclaimer in the documentation and/or other
+//    materials provided with the distribution.
+// 
+// 3. Neither the name of the copyright holder nor the names of its contributors may be
+//    used to endorse or promote products derived from this software without specific
+//    prior written permission.
+// 
+// THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS" AND ANY
+// EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED WARRANTIES OF
+// MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL
+// THE COPYRIGHT HOLDER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
+// SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO,
+// PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS
+// INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT,
+// STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF
+// THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
+
+const char * descr = 
+"This program prints the time (ms) needed to calculate a mathematical challenge. It's purpose \n\
+is to be able to use the result to compare the CPU power available on the machine it's being executed \n\
+and under the given circumstances, which can differ for the same machine. For example: \n\
+The printed value will be different when using 2 of 2 cores, when there an another process \n\
+running on one of the cores core, and when no other intense process running. \n\
+ \n\
+The program expects a one argument: a numerical value of the threads to start the calculations on. \n\
+ \n\
+Prints: \n\
+Time to calculate a mathematical challenge in MILLISECONDS. \n\
+ \n\
+Returns: \n\
+0 on success, \n\
+1 on a missing argument, \n\
+2 on an incorrect format of the argument.\n";
+
+#include <iostream>
+#include <future>
+#include <vector>
+#include <sstream>
+#include <chrono>
+
+using namespace std;
+
+/**
+Uses Leibniz Formula for Pi.
+https://en.wikipedia.org/wiki/Leibniz_formula_for_%CF%80
+*/
+static double calcPi(const size_t max_iter)
+{
+    const double n = 4;
+    double pi = 0;
+    double d = 1;
+    for (size_t i = 1; i < max_iter; ++i)
+    {
+        const double a = 2.0 * (i % 2) - 1.0;
+        pi += a * n / d;
+        d += 2;
+    }
+    return pi;
+}
+
+int main(int argc, const char ** argv)
+{
+    const size_t max_iter = 1e9;
+    if (argc < 2)
+    {
+        cout << "Please pass the number of threads to run.\n";
+        
+        cout << '\n' << descr << '\n';
+        return 1;
+    }
+    
+    // Convert argument to an integer.
+    int numThreads = 1;
+    const char * numThreadsStr = argv[1];
+    std::istringstream iss(numThreadsStr);
+    if (! (iss >> numThreads) )
+    {
+        cout << "Incorrect format of number of threads = '" << numThreadsStr << "'\n";
+        return 2;
+    }
+    // Run the calculation in parallel.
+    std::vector<std::future<double>> futures;
+    for(int i = 0; i < numThreads; ++i) 
+    {
+        futures.push_back(std::async(calcPi, max_iter));
+    }    
+    
+    // Start measuring the time.
+    const std::chrono::steady_clock::time_point tbegin = std::chrono::steady_clock::now();
+    for(auto & e : futures) 
+    {
+       e.get();
+    }
+    // Stop measuring the time.
+    const std::chrono::steady_clock::time_point tend = std::chrono::steady_clock::now();
+    
+    // Print the measured duration.
+    cout << std::chrono::duration_cast<std::chrono::milliseconds>(tend - tbegin).count() << std::endl;
+    return 0;
+}
+
diff --git a/tests/functional_tests/mining.py b/tests/functional_tests/mining.py
index 50bfd32a2..cb2fd66e1 100755
--- a/tests/functional_tests/mining.py
+++ b/tests/functional_tests/mining.py
@@ -31,6 +31,10 @@
 from __future__ import print_function
 import time
 import os
+import math
+import monotonic
+import util_resources
+import multiprocessing
 
 """Test daemon mining RPC calls
 
@@ -71,12 +75,20 @@ class MiningTest():
     def mine(self, via_daemon):
         print("Test mining via " + ("daemon" if via_daemon else "wallet"))
 
+        cores_init = multiprocessing.cpu_count() # RX init uses all cores
+        cores_mine = 1                           # Mining uses a parametric number of cores
+        time_pi_single_cpu = self.measure_cpu_power_get_time(cores_mine)
+        time_pi_all_cores = self.measure_cpu_power_get_time(cores_init)
+        # This is the last measurement, since it takes very little time and can be placed timewise-closer to the mining itself.
+        available_ram = self.get_available_ram() # So far no ideas how to use this var, other than printing it
+
+        start = monotonic.monotonic()
         daemon = Daemon()
         wallet = Wallet()
 
         # check info/height/balance before generating blocks
         res_info = daemon.get_info()
-        prev_height = res_info.height
+        initial_height = res_info.height
         res_getbalance = wallet.get_balance()
         prev_balance = res_getbalance.balance
 
@@ -85,29 +97,71 @@ class MiningTest():
         if via_daemon:
             res = daemon.start_mining('42ey1afDFnn4886T7196doS9GPMzexD9gXpsZJDwVjeRVdFCSoHnv7KPbBeGpzJBzHRCAs9UxqeoyFQMYbqSWYTfJJQAWDm', threads_count = 1)
         else:
-            res = wallet.start_mining(threads_count = 1)
+            res = wallet.start_mining(threads_count = cores_mine)
 
         res_status = daemon.mining_status()
         assert res_status.active == True
-        assert res_status.threads_count == 1
+        assert res_status.threads_count == cores_mine
         assert res_status.address == '42ey1afDFnn4886T7196doS9GPMzexD9gXpsZJDwVjeRVdFCSoHnv7KPbBeGpzJBzHRCAs9UxqeoyFQMYbqSWYTfJJQAWDm'
         assert res_status.is_background_mining_enabled == False
         assert res_status.block_reward >= 600000000000
 
         # wait till we mined a few of them
-        target_height = prev_height + 5
-        height = prev_height
-        timeout = 240 # randomx is slow to init
+        target_height = initial_height + 5
+        height = initial_height
+        
+        """
+        Randomx init has high variance on CI machines due to noisy neighbors, 
+        taking up resources in parallel (including by our own jobs).
+        
+        Mining is organized in the following scheme:
+            1) first loop's pass: RandomX init and mining
+            2) every next pass:   only mining
+        Pass 1) takes much more time than pass 2)
+        Pass 1) uses all cores, pass 2) just one (currently)
+        For the above reasons both passes need separate timeouts and adjustments.
+        After the first pass, the timeout is being reset to a lower value.
+        """
+        
+        def calc_timeout(seconds_constant, time_pi, cores):
+            """
+            The time it took to calculate pi under certain conditions 
+            is proportional to the time it will take to calculate the real job.
+            
+            The number of cores used decreases the time almost linearly.
+            """
+            timeout = float(seconds_constant) * time_pi / float(cores)
+            return timeout
+
+        timeout_base_init = 60 # RX init needs more time
+        timeout_base_mine = 20
+        timeout_init = calc_timeout(timeout_base_init, time_pi_all_cores,  cores_init)
+        timeout_mine = calc_timeout(timeout_base_mine, time_pi_single_cpu, cores_mine)
+        
+        msg = "Timeout for {} adjusted for the currently available CPU power, is {:.1f} s"
+        print(msg.format("init,  ", timeout_init))
+        print(msg.format("mining,", timeout_mine))
+        
+        timeout = timeout_init
+        rx_inited = False  # Gets initialized in the first pass of the below loop
         while height < target_height:
             seen_height = height
-            for _ in range(timeout):
+            for _ in range(int(math.ceil(timeout))):
                 time.sleep(1)
+                seconds_passed = monotonic.monotonic() - start
                 height = daemon.get_info().height
                 if height > seen_height:
                     break
             else:
-                assert False, 'Failed to mine successor to block %d (initial block = %d)' % (seen_height, prev_height)
-            timeout = 10
+                assert False, 'Failed to mine successor to block %d (initial block = %d) after %d s. RX initialized = %r' % (seen_height, initial_height, round(seconds_passed), rx_inited)
+            if not rx_inited:
+                rx_inited = True
+                timeout = timeout_mine # Resetting the timeout after first mined block and RX init
+                self.print_time_taken(start, "RX init + mining 1st block")
+            else:
+                self.print_time_taken(start, "mining iteration")
+
+        self.print_time_taken(start, "mining total")
 
         if via_daemon:
             res = daemon.stop_mining()
@@ -123,7 +177,7 @@ class MiningTest():
         wallet.refresh()
         res_getbalance = wallet.get_balance()
         balance = res_getbalance.balance
-        assert balance >= prev_balance + (new_height - prev_height) * 600000000000
+        assert balance >= prev_balance + (new_height - initial_height) * 600000000000
 
         if via_daemon:
             res = daemon.start_mining('42ey1afDFnn4886T7196doS9GPMzexD9gXpsZJDwVjeRVdFCSoHnv7KPbBeGpzJBzHRCAs9UxqeoyFQMYbqSWYTfJJQAWDm', threads_count = 1, do_background_mining = True)
@@ -143,6 +197,22 @@ class MiningTest():
             res = wallet.stop_mining()
         res_status = daemon.mining_status()
         assert res_status.active == False
+        
+    def measure_cpu_power_get_time(self, cores):
+        print("Measuring the currently available CPU power...")
+        time_pi = util_resources.get_time_pi_seconds(cores)
+        print("Time taken to calculate Pi on {} core(s) was {:.2f} s.".format(cores, time_pi))
+        return time_pi
+    
+    def get_available_ram(self):
+        available_ram = util_resources.available_ram_gb()
+        threshold_ram = 3
+        print("Available RAM =", round(available_ram, 1), "GB")
+        if available_ram < threshold_ram:
+            print("Warning! Available RAM =", round(available_ram, 1), 
+                  "GB is less than the reasonable threshold =", threshold_ram,
+                  ". The RX init might exceed the calculated timeout.")
+        return available_ram
 
     def submitblock(self):
         print("Test submitblock")
@@ -170,6 +240,10 @@ class MiningTest():
             res = daemon.get_height()
             assert res.height == height + i + 1
             assert res.hash == block_hash
+            
+    def print_time_taken(self, start, msg_context):
+        seconds_passed = monotonic.monotonic() - start
+        print("Time taken for", msg_context, "=", round(seconds_passed, 1), "s.")
 
     def test_randomx(self):
         print("Test RandomX")
diff --git a/tests/functional_tests/util_resources.py b/tests/functional_tests/util_resources.py
new file mode 100755
index 000000000..e45122e66
--- /dev/null
+++ b/tests/functional_tests/util_resources.py
@@ -0,0 +1,52 @@
+#!/usr/bin/env python3
+
+# Copyright (c) 2021 The Monero Project
+#
+# All rights reserved.
+#
+# Redistribution and use in source and binary forms, with or without modification, are
+# permitted provided that the following conditions are met:
+#
+# 1. Redistributions of source code must retain the above copyright notice, this list of
+#    conditions and the following disclaimer.
+#
+# 2. Redistributions in binary form must reproduce the above copyright notice, this list
+#    of conditions and the following disclaimer in the documentation and/or other
+#    materials provided with the distribution.
+#
+# 3. Neither the name of the copyright holder nor the names of its contributors may be
+#    used to endorse or promote products derived from this software without specific
+#    prior written permission.
+#
+# THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS" AND ANY
+# EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED WARRANTIES OF
+# MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL
+# THE COPYRIGHT HOLDER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
+# SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO,
+# PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS
+# INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT,
+# STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF
+# THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
+
+"""
+    Help determine how much CPU power is available at the given time
+    by running numerical calculations
+"""
+
+from __future__ import print_function
+import subprocess
+import psutil
+
+def available_ram_gb():
+    ram_bytes = psutil.virtual_memory().available
+    kilo = 1024.0
+    ram_gb = ram_bytes / kilo**3
+    return ram_gb
+
+def get_time_pi_seconds(cores):
+    app_path = './cpu_power_test'
+    time_calc = subprocess.check_output([app_path, str(cores)])
+    decoded = time_calc.decode('utf-8')
+    miliseconds = int(decoded)
+
+    return miliseconds / 1000.0