diff --git a/crypto/block/transaction.cpp b/crypto/block/transaction.cpp index e5cd701d..f5fb18f1 100644 --- a/crypto/block/transaction.cpp +++ b/crypto/block/transaction.cpp @@ -25,6 +25,41 @@ #include "ton/ton-shard.h" #include "vm/vm.h" +namespace { +class StringLoggerTail : public td::LogInterface { + public: + explicit StringLoggerTail(size_t max_size = 256) : buf(max_size, '\0') {} + void append(td::CSlice slice) override { + if (slice.size() > buf.size()) { + slice.remove_prefix(slice.size() - buf.size()); + } + while (!slice.empty()) { + size_t s = std::min(buf.size() - pos, slice.size()); + std::copy(slice.begin(), slice.begin() + s, buf.begin() + pos); + pos += s; + if (pos == buf.size()) { + pos = 0; + truncated = true; + } + slice.remove_prefix(s); + } + } + std::string get_log() const { + if (truncated) { + std::string res = buf; + std::rotate(res.begin(), res.begin() + pos, res.end()); + return res; + } else { + return buf.substr(0, pos); + } + } + private: + std::string buf; + size_t pos = 0; + bool truncated = false; +}; +} + namespace block { using td::Ref; @@ -1001,7 +1036,14 @@ bool Transaction::prepare_compute_phase(const ComputePhaseConfig& cfg) { vm::GasLimits gas{(long long)cp.gas_limit, (long long)cp.gas_max, (long long)cp.gas_credit}; LOG(DEBUG) << "creating VM"; - vm::VmState vm{new_code, std::move(stack), gas, 1, new_data, vm::VmLog(), compute_vm_libraries(cfg)}; + std::unique_ptr logger; + auto vm_log = vm::VmLog(); + if (cfg.with_vm_log) { + logger = std::make_unique(); + vm_log.log_interface = logger.get(); + vm_log.log_options = td::LogOptions(VERBOSITY_NAME(DEBUG), true, false); + } + vm::VmState vm{new_code, std::move(stack), gas, 1, new_data, vm_log, compute_vm_libraries(cfg)}; vm.set_c7(prepare_vm_c7(cfg)); // tuple with SmartContractInfo // vm.incr_stack_trace(1); // enable stack dump after each step @@ -1024,6 +1066,9 @@ bool Transaction::prepare_compute_phase(const ComputePhaseConfig& cfg) { LOG(INFO) << "steps: " << vm.get_steps_count() << " gas: used=" << gas.gas_consumed() << ", max=" << gas.gas_max << ", limit=" << gas.gas_limit << ", credit=" << gas.gas_credit; LOG(INFO) << "out_of_gas=" << cp.out_of_gas << ", accepted=" << cp.accepted << ", success=" << cp.success; + if (logger != nullptr) { + cp.vm_log = logger->get_log(); + } if (cp.success) { cp.new_data = vm.get_committed_state().c4; // c4 -> persistent data cp.actions = vm.get_committed_state().c5; // c5 -> action list diff --git a/crypto/block/transaction.h b/crypto/block/transaction.h index 398e2731..75762260 100644 --- a/crypto/block/transaction.h +++ b/crypto/block/transaction.h @@ -106,6 +106,7 @@ struct ComputePhaseConfig { std::unique_ptr libraries; Ref global_config; td::BitArray<256> block_rand_seed; + bool with_vm_log{false}; ComputePhaseConfig(td::uint64 _gas_price = 0, td::uint64 _gas_limit = 0, td::uint64 _gas_credit = 0) : gas_price(_gas_price), gas_limit(_gas_limit), special_gas_limit(_gas_limit), gas_credit(_gas_credit) { compute_threshold(); @@ -171,6 +172,7 @@ struct ComputePhase { Ref in_msg; Ref new_data; Ref actions; + std::string vm_log; }; struct ActionPhase { diff --git a/validator/impl/collator.cpp b/validator/impl/collator.cpp index 5820a2ce..798e6564 100644 --- a/validator/impl/collator.cpp +++ b/validator/impl/collator.cpp @@ -2326,7 +2326,12 @@ td::Result> Collator::impl_create_ordinary_t if (!trans->compute_phase->accepted) { if (external) { // inbound external message was not accepted - return td::Status::Error(-701,"inbound external message rejected by transaction "s + acc->addr.to_hex()); + auto const& cp = *trans->compute_phase; + return td::Status::Error( + -701, + PSLICE() << "inbound external message rejected by transaction " << acc->addr.to_hex() << ":\n" << + "exitcode=" << cp.exit_code << ", steps=" << cp.vm_steps << ", gas_used=" << cp.gas_used << + (cp.vm_log.empty() ? "" : "\nVM Log (truncated):\n..." + cp.vm_log)); } else if (trans->compute_phase->skip_reason == block::ComputePhase::sk_none) { return td::Status::Error(-669,"new ordinary transaction for smart contract "s + acc->addr.to_hex() + " has not been accepted by the smart contract (?)"); diff --git a/validator/impl/external-message.cpp b/validator/impl/external-message.cpp index c5f2d097..755370ca 100644 --- a/validator/impl/external-message.cpp +++ b/validator/impl/external-message.cpp @@ -112,10 +112,12 @@ void ExtMessageQ::run_message(td::BufferSlice data, td::actor::ActorId msg_root, - std::unique_ptr config) { +td::Status ExtMessageQ::run_message_on_account(ton::WorkchainId wc, + block::Account* acc, + UnixTime utime, LogicalTime lt, + td::Ref msg_root, + std::unique_ptr config) { Ref old_mparams; std::vector storage_prices_; @@ -143,28 +145,29 @@ bool ExtMessageQ::run_message_on_account(ton::WorkchainId wc, &action_phase_cfg_, &masterchain_create_fee, &basechain_create_fee, wc); if(fetch_res.is_error()) { - auto error = fetch_res.move_as_error(); - LOG(DEBUG) << "Cannot fetch config params" << error.message(); - return false; + auto error = fetch_res.move_as_error(); + LOG(DEBUG) << "Cannot fetch config params: " << error.message(); + return error.move_as_error_prefix("Cannot fetch config params: "); } + compute_phase_cfg_.with_vm_log = true; auto res = Collator::impl_create_ordinary_transaction(msg_root, acc, utime, lt, &storage_phase_cfg_, &compute_phase_cfg_, &action_phase_cfg_, true, lt); if(res.is_error()) { - auto error = res.move_as_error(); - LOG(DEBUG) << "Cannot run message on account" << error.message(); - return false; + auto error = res.move_as_error(); + LOG(DEBUG) << "Cannot run message on account: " << error.message(); + return error.move_as_error_prefix("Cannot run message on account: "); } std::unique_ptr trans = res.move_as_ok(); auto trans_root = trans->commit(*acc); if (trans_root.is_null()) { - LOG(DEBUG) << "cannot commit new transaction for smart contract "; - return false; + LOG(DEBUG) << "Cannot commit new transaction for smart contract"; + return td::Status::Error("Cannot commit new transaction for smart contract"); } - return true; + return td::Status::OK(); } } // namespace validator diff --git a/validator/impl/external-message.hpp b/validator/impl/external-message.hpp index 230258cd..1d1ec640 100644 --- a/validator/impl/external-message.hpp +++ b/validator/impl/external-message.hpp @@ -63,11 +63,11 @@ class ExtMessageQ : public ExtMessage { static td::Result> create_ext_message(td::BufferSlice data); static void run_message(td::BufferSlice data, td::actor::ActorId manager, td::Promise promise); - static bool run_message_on_account(ton::WorkchainId wc, - block::Account* acc, - UnixTime utime, LogicalTime lt, - td::Ref msg_root, - std::unique_ptr config); + static td::Status run_message_on_account(ton::WorkchainId wc, + block::Account* acc, + UnixTime utime, LogicalTime lt, + td::Ref msg_root, + std::unique_ptr config); }; } // namespace validator diff --git a/validator/impl/liteserver.cpp b/validator/impl/liteserver.cpp index 90d974e0..023a84ae 100644 --- a/validator/impl/liteserver.cpp +++ b/validator/impl/liteserver.cpp @@ -458,18 +458,20 @@ void LiteQuery::continue_getZeroState(BlockIdExt blkid, td::BufferSlice state) { void LiteQuery::perform_sendMessage(td::BufferSlice data) { LOG(INFO) << "started a sendMessage(<" << data.size() << " bytes>) liteserver query"; - td::actor::send_closure_later( - manager_, &ValidatorManager::check_external_message, data.clone(), - [Self = actor_id(this), data = std::move(data), manager = manager_](td::Result res) { + auto copy = data.clone(); + td::actor::send_closure_later( + manager_, &ValidatorManager::check_external_message, std::move(copy), + [Self = actor_id(this), data = std::move(data), manager = manager_](td::Result res) mutable { if(res.is_error()) { td::actor::send_closure(Self, &LiteQuery::abort_query, - res.move_as_error_prefix("cannot apply external message to current state : "s)); + res.move_as_error_prefix("cannot apply external message to current state : "s)); } else { - auto crm = ton::validator::create_ext_message(data.clone()); + auto crm = ton::validator::create_ext_message(std::move(data)); if (crm.is_error()) { //UNREACHABLE, checks in check_external_message, td::actor::send_closure(Self, &LiteQuery::abort_query, - crm.move_as_error()); + crm.move_as_error()); + return; } LOG(INFO) << "sending an external message to validator manager"; td::actor::send_closure_later(manager, &ValidatorManager::send_external_message, crm.move_as_ok());