Redirect syscall debug logs

crates/benches/benches/benchmarks/smt.rs

@@ -174,7 +174,12 @@ impl BenchExecutionEnvironment {
             manage
         };
 
-        let generator = Generator::new(backend_manage, account_lock_manage, rollup_context);
+        let generator = Generator::new(
+            backend_manage,
+            account_lock_manage,
+            rollup_context,
+            Default::default(),
+        );
 
         Self::init_genesis(&store, &genesis_config, accounts);
         let mem_pool_state = MemPoolState::new(Arc::new(MemStore::new(store.get_snapshot())), true);

crates/benches/benches/benchmarks/sudt.rs

@@ -89,7 +89,12 @@ fn run_contract_get_result<S: State + CodeStore>(
         rollup_config: rollup_config.clone(),
         rollup_script_hash: [42u8; 32].into(),
     };
-    let generator = Generator::new(backend_manage, account_lock_manage, rollup_ctx);
+    let generator = Generator::new(
+        backend_manage,
+        account_lock_manage,
+        rollup_ctx,
+        Default::default(),
+    );
     let chain_view = DummyChainStore;
     let run_result =
         generator.execute_transaction(&chain_view, tree, block_info, &raw_tx, L2TX_MAX_CYCLES)?;

crates/block-producer/src/runner.rs

@@ -478,6 +478,7 @@ impl BaseInitComponents {
                 backend_manage,
                 account_lock_manage,
                 rollup_context.clone(),
+                config.contract_log_config.clone(),
             ))
         };
 

crates/config/src/config.rs

@@ -20,6 +20,7 @@ pub enum Trace {
 #[derive(Clone, Default, Debug, PartialEq, Serialize, Deserialize)]
 pub struct Config {
     pub node_mode: NodeMode,
+    pub contract_log_config: ContractLogConfig,
     pub backend_switches: Vec<BackendSwitchConfig>,
     pub genesis: GenesisConfig,
     pub chain: ChainConfig,
@@ -411,3 +412,17 @@ pub struct DynamicConfig {
     pub fee_config: FeeConfig,
     pub rpc_config: RPCConfig,
 }
+
+#[derive(Clone, Debug, PartialEq, Serialize, Deserialize)]
+#[serde(rename_all = "lowercase")]
+pub enum ContractLogConfig {
+    Default,       //print contract log in place
+    Redirect,      //print all of the contract logs, send error logs to sentry
+    RedirectError, //only print logs when the tx hit an error, send error logs to sentry
+}
+
+impl Default for ContractLogConfig {
+    fn default() -> Self {
+        ContractLogConfig::Default
+    }
+}

crates/generator/Cargo.toml

@@ -33,7 +33,9 @@ tokio = "1.15"
 arc-swap = "1.5"
 ethabi = "16.0.0"
 tracing = { version = "0.1", features = ["attributes"] }
+sentry = { git = "https://github.com/getsentry/sentry-rust", rev = "df694a49595d6890c510d80b85cfbb4b5ae6159a" }
 
 [dev-dependencies]
 gw-utils = {path = "../utils" }
 tempfile = "3"
+sentry = { git = "https://github.com/getsentry/sentry-rust", rev = "df694a49595d6890c510d80b85cfbb4b5ae6159a", features=["test"] }

crates/generator/src/generator.rs

@@ -6,6 +6,7 @@ use crate::{
     constants::{L2TX_MAX_CYCLES, MAX_READ_DATA_BYTES_LIMIT, MAX_WRITE_DATA_BYTES_LIMIT},
     error::{BlockError, TransactionValidateError, WithdrawalError},
     run_result_state::RunResultState,
+    syscalls::redir_log::RedirLogHandler,
     typed_transaction::types::TypedRawTransaction,
     types::vm::VMVersion,
     utils::get_tx_type,
@@ -29,6 +30,7 @@ use gw_common::{
     },
     H256,
 };
+use gw_config::ContractLogConfig;
 use gw_store::{state::state_db::StateContext, transaction::StoreTransaction};
 use gw_traits::{ChainView, CodeStore};
 use gw_types::{
@@ -94,18 +96,22 @@ pub struct Generator {
     backend_manage: BackendManage,
     account_lock_manage: AccountLockManage,
     rollup_context: RollupContext,
+    redir_log_handler: RedirLogHandler,
 }
 
 impl Generator {
     pub fn new(
         backend_manage: BackendManage,
         account_lock_manage: AccountLockManage,
         rollup_context: RollupContext,
+        contract_log_config: ContractLogConfig,
     ) -> Self {
+        let redir_log_handler = RedirLogHandler::new(contract_log_config);
         Generator {
             backend_manage,
             account_lock_manage,
             rollup_context,
+            redir_log_handler,
         }
     }
 
@@ -129,6 +135,7 @@ impl Generator {
     ) -> Result<RunResult, TransactionError> {
         const INVALID_CYCLES_EXIT_CODE: i8 = -1;
 
+        self.redir_log_handler.start(raw_tx.clone());
         let mut run_result = RunResult::default();
         let used_cycles;
         let exit_code;
@@ -151,6 +158,7 @@ impl Generator {
                     account_lock_manage: &self.account_lock_manage,
                     result: &mut run_result,
                     code_store: state,
+                    redir_log_handler: &self.redir_log_handler,
                 }))
                 .instruction_cycle_func(Box::new(instruction_cycles));
             let default_machine = machine_builder.build();
@@ -185,6 +193,7 @@ impl Generator {
                     return Err(err.into());
                 }
             }
+            self.redir_log_handler.flush(exit_code);
             log::debug!(
                 "[execute tx] VM machine_run time: {}ms, exit code: {} used_cycles: {}",
                 t.elapsed().as_millis(),

crates/generator/src/syscalls/mod.rs

@@ -24,12 +24,17 @@ use gw_types::{
 };
 use std::cmp;
 
-use self::error_codes::{
-    GW_ERROR_ACCOUNT_NOT_FOUND, GW_ERROR_DUPLICATED_SCRIPT_HASH, GW_ERROR_INVALID_ACCOUNT_SCRIPT,
-    GW_ERROR_NOT_FOUND, GW_ERROR_RECOVER, GW_ERROR_UNKNOWN_SCRIPT_CODE_HASH, SUCCESS,
+use self::{
+    error_codes::{
+        GW_ERROR_ACCOUNT_NOT_FOUND, GW_ERROR_DUPLICATED_SCRIPT_HASH,
+        GW_ERROR_INVALID_ACCOUNT_SCRIPT, GW_ERROR_NOT_FOUND, GW_ERROR_RECOVER,
+        GW_ERROR_UNKNOWN_SCRIPT_CODE_HASH, SUCCESS,
+    },
+    redir_log::RedirLogHandler,
 };
 
 pub mod error_codes;
+pub(crate) mod redir_log;
 
 /* Constants */
 // 25KB is max ethereum contract code size
@@ -66,6 +71,7 @@ pub(crate) struct L2Syscalls<'a, S, C> {
     pub(crate) raw_tx: &'a RawL2Transaction,
     pub(crate) code_store: &'a dyn CodeStore,
     pub(crate) result: &'a mut RunResult,
+    pub(crate) redir_log_handler: &'a RedirLogHandler,
 }
 
 #[allow(dead_code)]
@@ -593,8 +599,7 @@ impl<'a, S: State, C: ChainView> L2Syscalls<'a, S, C> {
             addr += 1;
         }
 
-        let s = String::from_utf8(buffer).map_err(|_| VMError::ParseError)?;
-        log::debug!("[contract debug]: {}", s);
+        self.redir_log_handler.append_log(buffer);
         Ok(())
     }
 }

crates/generator/src/syscalls/redir_log.rs

@@ -0,0 +1,195 @@
+use gw_config::ContractLogConfig;
+use gw_types::{
+    bytes::{BufMut, BytesMut},
+    packed::RawL2Transaction,
+};
+use tokio::sync::mpsc;
+
+#[derive(Debug)]
+pub(crate) enum RedirLogMsg {
+    Session(RawL2Transaction),
+    Log(Vec<u8>),
+    Flush(i8), //exit code
+}
+pub(crate) struct RedirLogActor {
+    recv: mpsc::Receiver<RedirLogMsg>,
+    ctx: Context,
+}
+
+impl RedirLogActor {
+    pub(crate) fn new(recv: mpsc::Receiver<RedirLogMsg>, config: ContractLogConfig) -> Self {
+        let ctx = Context::init(config);
+        Self { recv, ctx }
+    }
+
+    fn handle_msg(&mut self, msg: RedirLogMsg) {
+        match msg {
+            RedirLogMsg::Session(tx) => self.ctx.setup(tx),
+            RedirLogMsg::Log(log) => self.ctx.append_log(&log),
+            RedirLogMsg::Flush(exit_code) => self.ctx.flush(exit_code),
+        }
+    }
+}
+
+// We can store the whole context of contract execution with tx, logs and exit code.
+struct Context {
+    tx: Option<RawL2Transaction>,
+    sink: BytesMut,
+    config: ContractLogConfig,
+}
+
+impl Context {
+    fn init(config: ContractLogConfig) -> Self {
+        Self {
+            tx: None,
+            sink: BytesMut::with_capacity(1024),
+            config,
+        }
+    }
+
+    fn setup(&mut self, tx: RawL2Transaction) {
+        self.tx = Some(tx);
+    }
+
+    fn append_log(&mut self, log: &[u8]) {
+        self.sink.put(log);
+        self.sink.put_u8(b'\n');
+    }
+
+    fn flush(&mut self, exit_code: i8) {
+        if let Ok(s) = std::str::from_utf8(&self.sink) {
+            if self.config == ContractLogConfig::Redirect
+                || (self.config == ContractLogConfig::RedirectError && exit_code != 0)
+            {
+                log::debug!("[contract debug]: {}", s);
+                log::debug!("contract exit code: {}", exit_code);
+            }
+            //send to senty if exit code != 0
+            //format:
+            //  tx_hash
+            //  [contrace logs]
+            //  ...
+            //  exit code: 3
+            if exit_code != 0 {
+                let mut entries: Vec<String> = Vec::with_capacity(3);
+                if let Some(tx) = &self.tx {
+                    let tx_hash = hex::encode(tx.as_reader().hash());
+                    entries.push(tx_hash);
+                }
+                entries.push(s.to_string());
+                entries.push(format!("exit code: {}", exit_code));
+                let msg = entries.join("\n");
+                sentry::capture_message(&msg, sentry::Level::Error);
+            }
+        }
+        self.sink.clear();
+        self.tx = None;
+    }
+}
+
+async fn run_redir_log_actor(mut actor: RedirLogActor) {
+    while let Some(msg) = actor.recv.recv().await {
+        actor.handle_msg(msg);
+    }
+}
+
+#[derive(Clone)]
+pub(crate) struct RedirLogHandler {
+    sender: Option<mpsc::Sender<RedirLogMsg>>,
+}
+
+impl RedirLogHandler {
+    pub(crate) fn new(config: ContractLogConfig) -> Self {
+        //Don't spawn tokio task in default mode.
+        let sender = if config != ContractLogConfig::Default {
+            let (sender, receiver) = mpsc::channel(16);
+            let actor = RedirLogActor::new(receiver, config);
+            tokio::spawn(run_redir_log_actor(actor));
+            Some(sender)
+        } else {
+            None
+        };
+        Self { sender }
+    }
+
+    pub(crate) fn start(&self, tx: RawL2Transaction) {
+        self.send_msg(RedirLogMsg::Session(tx));
+    }
+
+    pub(crate) fn flush(&self, exit_code: i8) {
+        self.send_msg(RedirLogMsg::Flush(exit_code));
+    }
+
+    pub(crate) fn append_log(&self, log: Vec<u8>) {
+        self.send_msg(RedirLogMsg::Log(log));
+    }
+
+    fn send_msg(&self, msg: RedirLogMsg) {
+        match &self.sender {
+            Some(sender) => match sender.try_send(msg) {
+                Ok(_) => log::trace!("redir log msg was sent out."),
+                Err(mpsc::error::TrySendError::Closed(msg)) => {
+                    log::warn!(
+                        "Discard redir log msg due to channel was closed. msg: {:?}",
+                        msg
+                    )
+                }
+                Err(mpsc::error::TrySendError::Full(msg)) => {
+                    log::warn!(
+                        "Discard redir log msg due to channel is full. msg: {:?}",
+                        msg
+                    )
+                }
+            },
+            None => {
+                if let RedirLogMsg::Log(log) = msg {
+                    if let Ok(s) = std::str::from_utf8(&log) {
+                        log::debug!("[contract debug]: {}", s);
+                    }
+                }
+            }
+        }
+    }
+}
+
+#[cfg(test)]
+mod tests {
+    use gw_types::{packed::RawL2Transaction, prelude::*};
+
+    use super::{Context, RedirLogHandler};
+
+    #[test]
+    fn redir_sentry_test() {
+        let mut ctx = Context::init(gw_config::ContractLogConfig::Redirect);
+        let tx = RawL2Transaction::new_builder()
+            .chain_id(0.pack())
+            .from_id(1u32.pack())
+            .to_id(2u32.pack())
+            .nonce(0u32.pack())
+            .build();
+
+        let event = sentry::test::with_captured_events(|| {
+            ctx.setup(tx.clone());
+            ctx.append_log(b"debug log");
+            ctx.flush(1);
+        });
+        let target = Some("05bb2c2e17393dea8bd1206a0b2ab104dec2593f1b91be4d764d3904b3a56847\ndebug log\n\nexit code: 1".to_string());
+        assert_eq!(target, event[0].message);
+    }
+
+    #[test]
+    #[should_panic(
+        expected = "there is no reactor running, must be called from the context of a Tokio 1.x runtime"
+    )]
+    fn redir_panic_test() {
+        let _handler = RedirLogHandler::new(gw_config::ContractLogConfig::Redirect);
+    }
+
+    #[test]
+    #[should_panic(
+        expected = "there is no reactor running, must be called from the context of a Tokio 1.x runtime"
+    )]
+    fn redir_err_panic_test() {
+        let _handler = RedirLogHandler::new(gw_config::ContractLogConfig::RedirectError);
+    }
+}

crates/replay-chain/src/setup.rs

@@ -121,6 +121,7 @@ pub async fn setup(args: SetupArgs) -> Result<Context> {
             backend_manage,
             account_lock_manage,
             rollup_context,
+            Default::default(),
         ))
     };