Adds a script for testing opcode timing and gas costs (#537)

* Adds a utility to test opcode timing and gas costs

* Remove unnecessary dependencies

* Adds a missing error code parameter

utils/CMakeLists.txt

@@ -20,4 +20,9 @@ target_link_libraries(pack-viewer tl_api ton_crypto keys validator tddb)
 target_include_directories(pack-viewer PUBLIC
   $<BUILD_INTERFACE:${CMAKE_CURRENT_SOURCE_DIR}>/..)
 
+add_executable(opcode-timing opcode-timing.cpp )
+target_link_libraries(opcode-timing ton_crypto)
+target_include_directories(pack-viewer PUBLIC
+        $<BUILD_INTERFACE:${CMAKE_CURRENT_SOURCE_DIR}>/..)
+
 install(TARGETS generate-random-id RUNTIME DESTINATION bin)

utils/opcode-timing.cpp

@@ -0,0 +1,171 @@
+#include <ctime>
+#include <iomanip>
+
+#include "vm/vm.h"
+#include "vm/cp0.h"
+#include "vm/dict.h"
+#include "fift/utils.h"
+#include "common/bigint.hpp"
+
+#include "td/utils/base64.h"
+#include "td/utils/tests.h"
+#include "td/utils/ScopeGuard.h"
+#include "td/utils/StringBuilder.h"
+
+td::Ref<vm::Cell> to_cell(const unsigned char *buff, int bits) {
+  return vm::CellBuilder().store_bits(buff, bits, 0).finalize();
+}
+
+long double timingBaseline;
+
+typedef struct {
+  long double mean;
+  long double stddev;
+} stats;
+
+struct runInfo {
+  long double runtime;
+  long long gasUsage;
+  int vmReturnCode;
+
+  runInfo() : runtime(0.0), gasUsage(0), vmReturnCode(0) {}
+  runInfo(long double runtime, long long gasUsage, int vmReturnCode) :
+      runtime(runtime), gasUsage(gasUsage), vmReturnCode(vmReturnCode) {}
+
+  runInfo operator+(const runInfo& addend) const {
+    return {runtime + addend.runtime, gasUsage + addend.gasUsage, vmReturnCode ? vmReturnCode : addend.vmReturnCode};
+  }
+
+  runInfo& operator+=(const runInfo& addend) {
+    runtime += addend.runtime;
+    gasUsage += addend.gasUsage;
+    if(!vmReturnCode && addend.vmReturnCode) {
+      vmReturnCode = addend.vmReturnCode;
+    }
+    return *this;
+  }
+
+  bool errored() const {
+    return vmReturnCode != 0;
+  }
+};
+
+typedef struct {
+  stats runtime;
+  stats gasUsage;
+  bool errored;
+} runtimeStats;
+
+runInfo time_run_vm(td::Slice command) {
+  unsigned char buff[128];
+  const int bits = (int)td::bitstring::parse_bitstring_hex_literal(buff, sizeof(buff), command.begin(), command.end());
+  CHECK(bits >= 0);
+
+  const auto cell = to_cell(buff, bits);
+
+  vm::init_op_cp0();
+  vm::DictionaryBase::get_empty_dictionary();
+
+  class Logger : public td::LogInterface {
+   public:
+    void append(td::CSlice slice) override {
+      res.append(slice.data(), slice.size());
+    }
+    std::string res;
+  };
+  static Logger logger;
+  logger.res = "";
+  td::set_log_fatal_error_callback([](td::CSlice message) { td::default_log_interface->append(logger.res); });
+  vm::VmLog log{&logger, td::LogOptions::plain()};
+  log.log_options.level = 4;
+  log.log_options.fix_newlines = true;
+  log.log_mask |= vm::VmLog::DumpStack;
+
+  vm::Stack stack;
+  try {
+    vm::GasLimits gas_limit(10000, 10000);
+
+    std::clock_t cStart = std::clock();
+    int ret = vm::run_vm_code(vm::load_cell_slice_ref(cell), stack, 0 /*flags*/, nullptr /*data*/,
+                              std::move(log) /*VmLog*/, nullptr, &gas_limit);
+    std::clock_t cEnd = std::clock();
+    const auto time = (1000.0 * static_cast<long double>(cEnd - cStart) / CLOCKS_PER_SEC) - timingBaseline;
+    return {time >= 0 ? time : 0, gas_limit.gas_consumed(), ret};
+  } catch (...) {
+    LOG(FATAL) << "catch unhandled exception";
+    return {-1, -1, 1};
+  }
+}
+
+runtimeStats averageRuntime(td::Slice command) {
+  const size_t samples = 5000;
+  runInfo total;
+  std::vector<runInfo> values;
+  values.reserve(samples);
+  for(size_t i=0; i<samples; ++i) {
+    const auto value = time_run_vm(command);
+    values.push_back(value);
+    total += value;
+  }
+  const auto runtimeMean = total.runtime / static_cast<long double>(samples);
+  const auto gasMean = static_cast<long double>(total.gasUsage) / static_cast<long double>(samples);
+  long double runtimeDiffSum = 0.0;
+  long double gasDiffSum = 0.0;
+  bool errored = false;
+  for(const auto value : values) {
+    const auto runtime = value.runtime - runtimeMean;
+    const auto gasUsage = static_cast<long double>(value.gasUsage) - gasMean;
+    runtimeDiffSum += runtime * runtime;
+    gasDiffSum += gasUsage * gasUsage;
+    errored = errored || value.errored();
+  }
+  return {
+      {runtimeMean, sqrt(runtimeDiffSum / static_cast<long double>(samples))},
+      {gasMean, sqrt(gasDiffSum / static_cast<long double>(samples))},
+      errored
+  };
+}
+
+runtimeStats timeInstruction(const std::string& setupCode, const std::string& toMeasure) {
+  const auto setupCodeTime = averageRuntime(setupCode);
+  const auto totalCodeTime = averageRuntime(setupCode + toMeasure);
+  return {
+      {totalCodeTime.runtime.mean - setupCodeTime.runtime.mean, totalCodeTime.runtime.stddev},
+      {totalCodeTime.gasUsage.mean - setupCodeTime.gasUsage.mean, totalCodeTime.gasUsage.stddev},
+      false
+  };
+}
+
+int main(int argc, char** argv) {
+  if(argc != 2 && argc != 3) {
+    std::cerr <<
+        "This utility compares the timing of VM execution against the gas used.\n"
+        "It can be used to discover opcodes or opcode sequences that consume an "
+        "inordinate amount of computational resources relative to their gas cost.\n"
+        "\n"
+        "The utility expects two command line arguments, each a hex string: \n"
+        "The TVM code used to set up the stack and VM state followed by the TVM code to measure.\n"
+        "For example, to test the DIVMODC opcode:\n"
+        "\t$ " << argv[0] << " 80FF801C A90E 2>/dev/null\n"
+        "\tOPCODE,runtime mean,runtime stddev,gas mean,gas stddev\n"
+        "\tA90E,0.0066416,0.00233496,26,0\n"
+        "\n"
+        "Usage: " << argv[0] <<
+        " [TVM_SETUP_BYTECODE_HEX] TVM_BYTECODE_HEX" << std::endl << std::endl;
+    return 1;
+  }
+  std::cout << "OPCODE,runtime mean,runtime stddev,gas mean,gas stddev" << std::endl;
+  timingBaseline = averageRuntime("").runtime.mean;
+  std::string setup, code;
+  if(argc == 2) {
+    setup = "";
+    code = argv[1];
+  } else {
+    setup = argv[1];
+    code = argv[2];
+  }
+  const auto time = timeInstruction(setup, code);
+  std::cout << code << "," << time.runtime.mean << "," << time.runtime.stddev << "," <<
+      time.gasUsage.mean << "," << time.gasUsage.stddev << std::endl;
+  return 0;
+}