[move] Support errors in traces for failed native calls (#20170)

## Description 

Adds support for recording errors from native functions in traces. 

## Test plan 

Added a new test that aborts inside of a native function and makes sure
that the abort is recored in the trace.

external-crates/move/crates/move-cli/tests/tracing_tests/tracing-unit-tests/args.exp

@@ -10,6 +10,7 @@ Running Move unit tests
 [ PASS    ] 0x1::errors::bad_cast
 [ PASS    ] 0x1::errors::div_0
 [ PASS    ] 0x1::errors::fail_during_abort
+[ PASS    ] 0x1::errors::fail_in_native
 [ PASS    ] 0x1::errors::overshift_l
 [ PASS    ] 0x1::errors::overshift_r
 [ PASS    ] 0x1::errors::underflow
@@ -24,5 +25,5 @@ Running Move unit tests
 [ PASS    ] 0x1::references::test_struct_borrow
 [ PASS    ] 0x1::references::test_vector_mut_borrow
 [ PASS    ] 0x1::references::test_vector_mut_borrow_pop
-Test result: OK. Total tests: 22; passed: 22; failed: 0
+Test result: OK. Total tests: 23; passed: 23; failed: 0
 External Command `diff -qr new_traces saved_traces`:

external-crates/move/crates/move-cli/tests/tracing_tests/tracing-unit-tests/new_traces/0x1__errors__fail_in_native.json

@@ -0,0 +1 @@
+{"events":[{"OpenFrame":{"frame":{"binary_member_index":7,"frame_id":0,"function_name":"fail_in_native","is_native":false,"locals_types":[{"ref_type":null,"type_":{"vector":"u8"}}],"module":{"address":"0000000000000000000000000000000000000000000000000000000000000001","name":"errors"},"parameters":[],"return_types":[],"type_instantiation":[]},"gas_left":1000000000}},{"Instruction":{"gas_left":999999992,"instruction":"LD_CONST","pc":0,"type_parameters":[]}},{"Effect":{"Push":{"RuntimeValue":{"value":[1,2,3]}}}},{"Instruction":{"gas_left":999999986,"instruction":"ST_LOC","pc":1,"type_parameters":[]}},{"Effect":{"Pop":{"RuntimeValue":{"value":[1,2,3]}}}},{"Effect":{"Write":{"location":{"Local":[0,0]},"root_value_after_write":{"RuntimeValue":{"value":[1,2,3]}}}}},{"Instruction":{"gas_left":999999984,"instruction":"IMM_BORROW_LOC","pc":2,"type_parameters":[]}},{"Effect":{"Read":{"location":{"Local":[0,0]},"moved":false,"root_value_read":{"RuntimeValue":{"value":[1,2,3]}}}}},{"Effect":{"Push":{"ImmRef":{"location":{"Local":[0,0]},"snapshot":[1,2,3]}}}},{"Instruction":{"gas_left":999999982,"instruction":"LD_U64","pc":3,"type_parameters":[]}},{"Effect":{"Push":{"RuntimeValue":{"value":4}}}},{"Instruction":{"gas_left":999999980,"instruction":"LD_U64","pc":4,"type_parameters":[]}},{"Effect":{"Push":{"RuntimeValue":{"value":1}}}},{"Instruction":{"gas_left":999999980,"instruction":"CALL","pc":5,"type_parameters":[]}},{"OpenFrame":{"frame":{"binary_member_index":17,"frame_id":14,"function_name":"internal_sub_string_for_testing","is_native":false,"locals_types":[{"ref_type":"Imm","type_":{"vector":"u8"}},{"ref_type":null,"type_":"u64"},{"ref_type":null,"type_":"u64"}],"module":{"address":"0000000000000000000000000000000000000000000000000000000000000001","name":"string"},"parameters":[{"ImmRef":{"location":{"Local":[0,0]},"snapshot":[1,2,3]}},{"RuntimeValue":{"value":4}},{"RuntimeValue":{"value":1}}],"return_types":[{"ref_type":null,"type_":{"vector":"u8"}}],"type_instantiation":[]},"gas_left":999999980}},{"Instruction":{"gas_left":999995432,"instruction":"MOVE_LOC","pc":0,"type_parameters":[]}},{"Effect":{"Read":{"location":{"Local":[14,0]},"moved":true,"root_value_read":{"ImmRef":{"location":{"Local":[0,0]},"snapshot":[1,2,3]}}}}},{"Effect":{"Push":{"ImmRef":{"location":{"Local":[0,0]},"snapshot":[1,2,3]}}}},{"Instruction":{"gas_left":999995400,"instruction":"MOVE_LOC","pc":1,"type_parameters":[]}},{"Effect":{"Read":{"location":{"Local":[14,1]},"moved":true,"root_value_read":{"RuntimeValue":{"value":4}}}}},{"Effect":{"Push":{"RuntimeValue":{"value":4}}}},{"Instruction":{"gas_left":999995368,"instruction":"MOVE_LOC","pc":2,"type_parameters":[]}},{"Effect":{"Read":{"location":{"Local":[14,2]},"moved":true,"root_value_read":{"RuntimeValue":{"value":1}}}}},{"Effect":{"Push":{"RuntimeValue":{"value":1}}}},{"Instruction":{"gas_left":999995368,"instruction":"CALL","pc":3,"type_parameters":[]}},{"OpenFrame":{"frame":{"binary_member_index":15,"frame_id":25,"function_name":"internal_sub_string","is_native":true,"locals_types":[{"ref_type":"Imm","type_":{"vector":"u8"}},{"ref_type":null,"type_":"u64"},{"ref_type":null,"type_":"u64"}],"module":{"address":"0000000000000000000000000000000000000000000000000000000000000001","name":"string"},"parameters":[{"ImmRef":{"location":{"Local":[0,0]},"snapshot":[1,2,3]}},{"RuntimeValue":{"value":4}},{"RuntimeValue":{"value":1}}],"return_types":[{"ref_type":null,"type_":{"vector":"u8"}}],"type_instantiation":[]},"gas_left":999995368}},{"Effect":{"ExecutionError":"ABORTED"}}],"version":1}

external-crates/move/crates/move-cli/tests/tracing_tests/tracing-unit-tests/saved_traces/0x1__errors__fail_in_native.json

@@ -0,0 +1 @@
+{"events":[{"OpenFrame":{"frame":{"binary_member_index":7,"frame_id":0,"function_name":"fail_in_native","is_native":false,"locals_types":[{"ref_type":null,"type_":{"vector":"u8"}}],"module":{"address":"0000000000000000000000000000000000000000000000000000000000000001","name":"errors"},"parameters":[],"return_types":[],"type_instantiation":[]},"gas_left":1000000000}},{"Instruction":{"gas_left":999999992,"instruction":"LD_CONST","pc":0,"type_parameters":[]}},{"Effect":{"Push":{"RuntimeValue":{"value":[1,2,3]}}}},{"Instruction":{"gas_left":999999986,"instruction":"ST_LOC","pc":1,"type_parameters":[]}},{"Effect":{"Pop":{"RuntimeValue":{"value":[1,2,3]}}}},{"Effect":{"Write":{"location":{"Local":[0,0]},"root_value_after_write":{"RuntimeValue":{"value":[1,2,3]}}}}},{"Instruction":{"gas_left":999999984,"instruction":"IMM_BORROW_LOC","pc":2,"type_parameters":[]}},{"Effect":{"Read":{"location":{"Local":[0,0]},"moved":false,"root_value_read":{"RuntimeValue":{"value":[1,2,3]}}}}},{"Effect":{"Push":{"ImmRef":{"location":{"Local":[0,0]},"snapshot":[1,2,3]}}}},{"Instruction":{"gas_left":999999982,"instruction":"LD_U64","pc":3,"type_parameters":[]}},{"Effect":{"Push":{"RuntimeValue":{"value":4}}}},{"Instruction":{"gas_left":999999980,"instruction":"LD_U64","pc":4,"type_parameters":[]}},{"Effect":{"Push":{"RuntimeValue":{"value":1}}}},{"Instruction":{"gas_left":999999980,"instruction":"CALL","pc":5,"type_parameters":[]}},{"OpenFrame":{"frame":{"binary_member_index":17,"frame_id":14,"function_name":"internal_sub_string_for_testing","is_native":false,"locals_types":[{"ref_type":"Imm","type_":{"vector":"u8"}},{"ref_type":null,"type_":"u64"},{"ref_type":null,"type_":"u64"}],"module":{"address":"0000000000000000000000000000000000000000000000000000000000000001","name":"string"},"parameters":[{"ImmRef":{"location":{"Local":[0,0]},"snapshot":[1,2,3]}},{"RuntimeValue":{"value":4}},{"RuntimeValue":{"value":1}}],"return_types":[{"ref_type":null,"type_":{"vector":"u8"}}],"type_instantiation":[]},"gas_left":999999980}},{"Instruction":{"gas_left":999995432,"instruction":"MOVE_LOC","pc":0,"type_parameters":[]}},{"Effect":{"Read":{"location":{"Local":[14,0]},"moved":true,"root_value_read":{"ImmRef":{"location":{"Local":[0,0]},"snapshot":[1,2,3]}}}}},{"Effect":{"Push":{"ImmRef":{"location":{"Local":[0,0]},"snapshot":[1,2,3]}}}},{"Instruction":{"gas_left":999995400,"instruction":"MOVE_LOC","pc":1,"type_parameters":[]}},{"Effect":{"Read":{"location":{"Local":[14,1]},"moved":true,"root_value_read":{"RuntimeValue":{"value":4}}}}},{"Effect":{"Push":{"RuntimeValue":{"value":4}}}},{"Instruction":{"gas_left":999995368,"instruction":"MOVE_LOC","pc":2,"type_parameters":[]}},{"Effect":{"Read":{"location":{"Local":[14,2]},"moved":true,"root_value_read":{"RuntimeValue":{"value":1}}}}},{"Effect":{"Push":{"RuntimeValue":{"value":1}}}},{"Instruction":{"gas_left":999995368,"instruction":"CALL","pc":3,"type_parameters":[]}},{"OpenFrame":{"frame":{"binary_member_index":15,"frame_id":25,"function_name":"internal_sub_string","is_native":true,"locals_types":[{"ref_type":"Imm","type_":{"vector":"u8"}},{"ref_type":null,"type_":"u64"},{"ref_type":null,"type_":"u64"}],"module":{"address":"0000000000000000000000000000000000000000000000000000000000000001","name":"string"},"parameters":[{"ImmRef":{"location":{"Local":[0,0]},"snapshot":[1,2,3]}},{"RuntimeValue":{"value":4}},{"RuntimeValue":{"value":1}}],"return_types":[{"ref_type":null,"type_":{"vector":"u8"}}],"type_instantiation":[]},"gas_left":999995368}},{"Effect":{"ExecutionError":"ABORTED"}}],"version":1}

external-crates/move/crates/move-cli/tests/tracing_tests/tracing-unit-tests/sources/errors.move

@@ -41,4 +41,10 @@ module 0x1::errors {
     fun fail_during_abort() {
         abort 1/0
     }
+
+    #[test]
+    #[expected_failure]
+    fun fail_in_native() {
+        std::string::internal_sub_string_for_testing(&vector[1, 2, 3], 4, 1);
+    }
 }

external-crates/move/crates/move-vm-runtime/src/interpreter.rs

@@ -146,11 +146,11 @@ impl Interpreter {
                 .map_err(|e| {
                     e.at_code_offset(function.index(), 0)
                         .finish(Location::Module(function.module_id().clone()))
-                })?;
+                });
 
             close_initial_frame!(tracer, &function, &return_values, gas_meter);
 
-            Ok(return_values.into_iter().collect())
+            Ok(return_values?.into_iter().collect())
         } else {
             interpreter.execute_main(
                 loader, data_store, gas_meter, extensions, function, ty_args, args, tracer,
@@ -216,7 +216,8 @@ impl Interpreter {
                         &self,
                         &loader,
                         gas_meter,
-                        link_context
+                        link_context,
+                        None
                     );
 
                     if let Some(frame) = self.call_stack.pop() {
@@ -256,9 +257,9 @@ impl Interpreter {
 
                     if func.is_native() {
                         let func_clone = func.clone();
-                        self.call_native(&resolver, gas_meter, extensions, func, vec![])?;
-
-                        current_frame.pc += 1; // advance past the Call instruction in the caller
+                        // Defer the error handling until we can trace the closure of the frame.
+                        let deferred_err =
+                            self.call_native(&resolver, gas_meter, extensions, func, vec![]);
 
                         close_frame!(
                             tracer,
@@ -267,8 +268,15 @@ impl Interpreter {
                             &self,
                             &loader,
                             gas_meter,
-                            link_context
+                            link_context,
+                            deferred_err.as_ref().err()
                         );
+
+                        // Now raise the error from the `call_native` if there was one.
+                        deferred_err?;
+
+                        current_frame.pc += 1; // advance past the Call instruction in the caller
+
                         continue;
                     }
                     let frame = self
@@ -316,18 +324,24 @@ impl Interpreter {
 
                     if func.is_native() {
                         let func_clone = func.clone();
-                        self.call_native(&resolver, gas_meter, extensions, func, ty_args)?;
-                        current_frame.pc += 1; // advance past the Call instruction in the caller
+                        // Defer the error handling until we can trace the closure of the frame.
+                        let deferred_err =
+                            self.call_native(&resolver, gas_meter, extensions, func, ty_args);
                         close_frame!(
                             tracer,
                             &current_frame,
                             &func_clone,
                             &self,
                             &loader,
                             gas_meter,
-                            link_context
+                            link_context,
+                            deferred_err.as_ref().err()
                         );
 
+                        // Now raise the error from the `call_native` if there was one.
+                        deferred_err?;
+
+                        current_frame.pc += 1; // advance past the Call instruction in the caller
                         continue;
                     }
                     let frame = self

external-crates/move/crates/move-vm-runtime/src/tracing2/mod.rs

@@ -39,7 +39,7 @@ macro_rules! close_initial_frame {
 
 #[macro_export]
 macro_rules! close_frame {
-    ($tracer: expr, $frame: expr, $function: expr, $interp: expr, $loader: expr, $gas_meter: expr, $link_context: expr) => {
+    ($tracer: expr, $frame: expr, $function: expr, $interp: expr, $loader: expr, $gas_meter: expr, $link_context: expr, $call_err: expr) => {
         if $crate::tracing2::TRACING_ENABLED {
             $tracer.as_mut().map(|tracer| {
                 tracer.close_frame(
@@ -49,6 +49,7 @@ macro_rules! close_frame {
                     $loader,
                     $gas_meter.remaining_gas().into(),
                     $link_context,
+                    $call_err,
                 )
             });
             move_vm_profiler::profile_close_frame!($gas_meter, $function.pretty_string());

external-crates/move/crates/move-vm-runtime/src/tracing2/tracer.rs

@@ -6,7 +6,7 @@ use crate::{
     loader::{Function, Loader},
 };
 use move_binary_format::{
-    errors::PartialVMError,
+    errors::{PartialVMError, VMError, VMResult},
     file_format::{ConstantPoolIndex, SignatureIndex},
 };
 use move_core_types::{
@@ -19,6 +19,7 @@ use move_trace_format::format::{
     TypeTagWithRefs, Write,
 };
 use move_vm_types::{loaded_data::runtime_types::Type, values::Value};
+use smallvec::SmallVec;
 use std::collections::BTreeMap;
 
 /// Internal state for the tracer. This is where the actual tracing logic is implemented.
@@ -1553,7 +1554,19 @@ impl<'a> VMTracer<'a> {
         self.emit_trace_error_if_err(opt.is_none());
     }
 
-    pub(crate) fn close_initial_frame(&mut self, return_values: &[Value], remaining_gas: u64) {
+    pub(crate) fn close_initial_frame(
+        &mut self,
+        return_values: &VMResult<SmallVec<[Value; 1]>>,
+        remaining_gas: u64,
+    ) {
+        let return_values = match return_values {
+            Ok(values) => values,
+            Err(err) => {
+                self.trace
+                    .effect(EF::ExecutionError(format!("{:?}", err.major_status())));
+                return;
+            }
+        };
         let opt = self.close_initial_frame_(return_values, remaining_gas);
         self.emit_trace_error_if_err(opt.is_none());
     }
@@ -1588,7 +1601,13 @@ impl<'a> VMTracer<'a> {
         loader: &Loader,
         remaining_gas: u64,
         link_context: AccountAddress,
+        err: Option<&VMError>,
     ) {
+        if let Some(err) = err {
+            self.trace
+                .effect(EF::ExecutionError(format!("{:?}", err.major_status())));
+            return;
+        }
         let opt = self.close_frame_(
             frame,
             function,