Add stable program logging for BPF and native programs

This commit is contained in:
Michael Vines
2020-11-12 12:44:37 -08:00
parent b3e1fde8b2
commit b4deeb8e36
9 changed files with 185 additions and 68 deletions

View File

@@ -24,7 +24,7 @@ use solana_sdk::{
instruction::InstructionError,
keyed_account::{is_executable, next_keyed_account, KeyedAccount},
loader_instruction::LoaderInstruction,
process_instruction::{ComputeMeter, Executor, InvokeContext},
process_instruction::{stable_log, ComputeMeter, Executor, InvokeContext},
program_utils::limited_deserialize,
pubkey::Pubkey,
};
@@ -62,7 +62,7 @@ pub enum BPFError {
impl UserDefinedError for BPFError {}
/// Point all log messages to the log collector
macro_rules! log{
macro_rules! log {
($logger:ident, $message:expr) => {
if let Ok(logger) = $logger.try_borrow_mut() {
if logger.log_enabled() {
@@ -229,6 +229,7 @@ impl Executor for BPFExecutor {
invoke_context: &mut dyn InvokeContext,
) -> Result<(), InstructionError> {
let logger = invoke_context.get_logger();
let invoke_depth = invoke_context.invoke_depth();
let mut keyed_accounts_iter = keyed_accounts.iter();
let program = next_keyed_account(&mut keyed_accounts_iter)?;
@@ -255,7 +256,7 @@ impl Executor for BPFExecutor {
}
};
log!(logger, "Call BPF program {}", program.unsigned_key());
stable_log::program_invoke(&logger, program.unsigned_key(), invoke_depth);
let instruction_meter = ThisInstructionMeter::new(compute_meter.clone());
let before = compute_meter.borrow().get_remaining();
let result = vm.execute_program_metered(
@@ -267,7 +268,8 @@ impl Executor for BPFExecutor {
let after = compute_meter.borrow().get_remaining();
log!(
logger,
"BPF program consumed {} of {} units",
"Program {} consumed {} of {} compute units",
program.unsigned_key(),
before - after,
before
);
@@ -275,33 +277,25 @@ impl Executor for BPFExecutor {
Ok(status) => {
if status != SUCCESS {
let error: InstructionError = status.into();
log!(
logger,
"BPF program {} failed: {}",
program.unsigned_key(),
error
);
stable_log::program_failure(&logger, program.unsigned_key(), &error);
return Err(error);
}
}
Err(error) => {
log!(
logger,
"BPF program {} failed: {}",
program.unsigned_key(),
error
);
return match error {
let error = match error {
EbpfError::UserError(BPFError::SyscallError(
SyscallError::InstructionError(error),
)) => Err(error),
_ => Err(BPFLoaderError::VirtualMachineFailedToRunProgram.into()),
)) => error,
_ => BPFLoaderError::VirtualMachineFailedToRunProgram.into(),
};
stable_log::program_failure(&logger, program.unsigned_key(), &error);
return Err(error);
}
}
}
deserialize_parameters(program_id, parameter_accounts, &parameter_bytes)?;
log!(logger, "BPF program {} success", program.unsigned_key());
stable_log::program_success(&logger, program.unsigned_key());
Ok(())
}
}

View File

@@ -21,7 +21,7 @@ use solana_sdk::{
instruction::{AccountMeta, Instruction, InstructionError},
keyed_account::KeyedAccount,
message::Message,
process_instruction::{ComputeMeter, InvokeContext, Logger},
process_instruction::{stable_log, ComputeMeter, InvokeContext, Logger},
program_error::ProgramError,
pubkey::{Pubkey, PubkeyError},
};
@@ -371,22 +371,16 @@ impl<'a> SyscallObject<BPFError> for SyscallLog<'a> {
_rw_regions: &[MemoryRegion],
) -> Result<u64, EbpfError<BPFError>> {
self.compute_meter.consume(self.cost)?;
let logger = self
.logger
.try_borrow_mut()
.map_err(|_| SyscallError::InvokeContextBorrowFailed)?;
if logger.log_enabled() {
translate_string_and_do(
addr,
len,
ro_regions,
&self.loader_id,
&mut |string: &str| {
logger.log(&format!("Program log: {}", string));
Ok(0)
},
)?;
}
translate_string_and_do(
addr,
len,
ro_regions,
&self.loader_id,
&mut |string: &str| {
stable_log::program_log(&self.logger, string);
Ok(0)
},
)?;
Ok(0)
}
}
@@ -409,16 +403,13 @@ impl SyscallObject<BPFError> for SyscallLogU64 {
_rw_regions: &[MemoryRegion],
) -> Result<u64, EbpfError<BPFError>> {
self.compute_meter.consume(self.cost)?;
let logger = self
.logger
.try_borrow_mut()
.map_err(|_| SyscallError::InvokeContextBorrowFailed)?;
if logger.log_enabled() {
logger.log(&format!(
"Program log: {:#x}, {:#x}, {:#x}, {:#x}, {:#x}",
stable_log::program_log(
&self.logger,
&format!(
"{:#x}, {:#x}, {:#x}, {:#x}, {:#x}",
arg1, arg2, arg3, arg4, arg5
));
}
),
);
Ok(0)
}
}
@@ -474,14 +465,8 @@ impl<'a> SyscallObject<BPFError> for SyscallLogPubkey<'a> {
_rw_regions: &[MemoryRegion],
) -> Result<u64, EbpfError<BPFError>> {
self.compute_meter.consume(self.cost)?;
let logger = self
.logger
.try_borrow_mut()
.map_err(|_| SyscallError::InvokeContextBorrowFailed)?;
if logger.log_enabled() {
let pubkey = translate_type!(Pubkey, pubkey_addr, ro_regions, self.loader_id)?;
logger.log(&format!("Program log: {}", pubkey));
}
let pubkey = translate_type!(Pubkey, pubkey_addr, ro_regions, self.loader_id)?;
stable_log::program_log(&self.logger, &pubkey.to_string());
Ok(0)
}
}