Add ic_msg()/ic_logger_msg() macros

This commit is contained in:
Michael Vines 2021-01-21 09:57:59 -08:00 committed by mergify[bot]
parent ca95302038
commit 3c6dbd21d2
2 changed files with 102 additions and 96 deletions

View File

@ -27,6 +27,7 @@ use solana_sdk::{
clock::Clock,
entrypoint::SUCCESS,
feature_set::{bpf_compute_budget_balancing, prevent_upgrade_and_invoke},
ic_logger_msg, ic_msg,
instruction::InstructionError,
keyed_account::{from_keyed_account, next_keyed_account, KeyedAccount},
loader_instruction::LoaderInstruction,
@ -56,30 +57,11 @@ pub enum BPFError {
}
impl UserDefinedError for BPFError {}
/// Point all log messages to the log collector
macro_rules! log {
($logger:ident, $message:expr) => {
if let Ok(logger) = $logger.try_borrow_mut() {
if logger.log_enabled() {
logger.log($message);
}
}
};
($logger:ident, $fmt:expr, $($arg:tt)*) => {
if let Ok(logger) = $logger.try_borrow_mut() {
if logger.log_enabled() {
logger.log(&format!($fmt, $($arg)*));
}
}
};
}
fn map_ebpf_error(
invoke_context: &mut dyn InvokeContext,
e: EbpfError<BPFError>,
) -> InstructionError {
let logger = invoke_context.get_logger();
log!(logger, "{}", e);
ic_msg!(invoke_context, "{}", e);
InstructionError::InvalidAccountData
}
@ -89,8 +71,6 @@ pub fn create_and_cache_executor(
invoke_context: &mut dyn InvokeContext,
use_jit: bool,
) -> Result<Arc<BPFExecutor>, InstructionError> {
let logger = invoke_context.get_logger();
let bpf_compute_budget = invoke_context.get_bpf_compute_budget();
let mut program = Executable::<BPFError, ThisInstructionMeter>::from_elf(
data,
@ -112,13 +92,13 @@ pub fn create_and_cache_executor(
)
.map_err(|e| map_ebpf_error(invoke_context, EbpfError::UserError(e)))?;
let syscall_registry = syscalls::register_syscalls(invoke_context).map_err(|e| {
log!(logger, "Failed to register syscalls: {}", e);
ic_msg!(invoke_context, "Failed to register syscalls: {}", e);
InstructionError::ProgramEnvironmentSetupFailure
})?;
program.set_syscall_registry(syscall_registry);
if use_jit {
if let Err(err) = program.jit_compile() {
log!(logger, "Failed to compile program {:?}", err);
ic_msg!(invoke_context, "Failed to compile program {:?}", err);
return Err(InstructionError::ProgramFailedToCompile);
}
}
@ -133,11 +113,14 @@ fn write_program_data(
bytes: &[u8],
invoke_context: &mut dyn InvokeContext,
) -> Result<(), InstructionError> {
let logger = invoke_context.get_logger();
let len = bytes.len();
if data.len() < offset + len {
log!(logger, "Write overflow: {} < {}", data.len(), offset + len);
ic_msg!(
invoke_context,
"Write overflow: {} < {}",
data.len(),
offset + len
);
return Err(InstructionError::AccountDataTooSmall);
}
data[offset..offset + len].copy_from_slice(&bytes);
@ -218,7 +201,7 @@ fn process_instruction_common(
let first_account = next_keyed_account(account_iter)?;
if first_account.executable()? {
if first_account.unsigned_key() != program_id {
log!(logger, "Program id mismatch");
ic_logger_msg!(logger, "Program id mismatch");
return Err(InstructionError::IncorrectProgramId);
}
@ -230,7 +213,10 @@ fn process_instruction_common(
{
let programdata = next_keyed_account(account_iter)?;
if programdata_address != *programdata.unsigned_key() {
log!(logger, "Wrong ProgramData account for this Program account");
ic_logger_msg!(
logger,
"Wrong ProgramData account for this Program account"
);
return Err(InstructionError::InvalidArgument);
}
(
@ -239,7 +225,7 @@ fn process_instruction_common(
UpgradeableLoaderState::programdata_data_offset()?,
)
} else {
log!(logger, "Invalid Program account");
ic_logger_msg!(logger, "Invalid Program account");
return Err(InstructionError::InvalidAccountData);
}
} else {
@ -249,7 +235,7 @@ fn process_instruction_common(
let loader_id = &program.owner()?;
if !check_loader_id(loader_id) {
log!(logger, "Executable account not owned by the BPF loader");
ic_logger_msg!(logger, "Executable account not owned by the BPF loader");
return Err(InstructionError::IncorrectProgramId);
}
@ -272,7 +258,7 @@ fn process_instruction_common(
)?
} else {
if !check_loader_id(program_id) {
log!(logger, "Invalid BPF loader id");
ic_logger_msg!(logger, "Invalid BPF loader id");
return Err(InstructionError::IncorrectProgramId);
}
@ -315,7 +301,7 @@ fn process_loader_upgradeable_instruction(
.map(|account| account.unsigned_key());
if UpgradeableLoaderState::Uninitialized != buffer.state()? {
log!(logger, "Buffer account already initialized");
ic_logger_msg!(logger, "Buffer account already initialized");
return Err(InstructionError::AccountAlreadyInitialized);
}
buffer.set_state(&UpgradeableLoaderState::Buffer {
@ -328,19 +314,19 @@ fn process_loader_upgradeable_instruction(
if let UpgradeableLoaderState::Buffer { authority_address } = buffer.state()? {
if authority_address == None {
log!(logger, "Buffer is immutable");
ic_logger_msg!(logger, "Buffer is immutable");
return Err(InstructionError::Immutable); // TODO better error code
}
if authority_address != Some(*authority.unsigned_key()) {
log!(logger, "Incorrect buffer authority provided");
ic_logger_msg!(logger, "Incorrect buffer authority provided");
return Err(InstructionError::IncorrectAuthority);
}
if authority.signer_key().is_none() {
log!(logger, "Buffer authority did not sign");
ic_logger_msg!(logger, "Buffer authority did not sign");
return Err(InstructionError::MissingRequiredSignature);
}
} else {
log!(logger, "Invalid Buffer account");
ic_logger_msg!(logger, "Invalid Buffer account");
return Err(InstructionError::InvalidAccountData);
}
write_program_data(
@ -365,15 +351,15 @@ fn process_loader_upgradeable_instruction(
// Verify Program account
if UpgradeableLoaderState::Uninitialized != program.state()? {
log!(logger, "Program account already initialized");
ic_logger_msg!(logger, "Program account already initialized");
return Err(InstructionError::AccountAlreadyInitialized);
}
if program.data_len()? < UpgradeableLoaderState::program_len()? {
log!(logger, "Program account too small");
ic_logger_msg!(logger, "Program account too small");
return Err(InstructionError::AccountDataTooSmall);
}
if program.lamports()? < rent.minimum_balance(program.data_len()?) {
log!(logger, "Program account not rent-exempt");
ic_logger_msg!(logger, "Program account not rent-exempt");
return Err(InstructionError::ExecutableAccountNotRentExempt);
}
@ -384,7 +370,7 @@ fn process_loader_upgradeable_instruction(
} = buffer.state()?
{
} else {
log!(logger, "Invalid Buffer account");
ic_logger_msg!(logger, "Invalid Buffer account");
return Err(InstructionError::InvalidArgument);
}
@ -395,11 +381,11 @@ fn process_loader_upgradeable_instruction(
if buffer.data_len()? < UpgradeableLoaderState::buffer_data_offset()?
|| buffer_data_len == 0
{
log!(logger, "Buffer account too small");
ic_logger_msg!(logger, "Buffer account too small");
return Err(InstructionError::InvalidAccountData);
}
if max_data_len < buffer_data_len {
log!(logger, "Max data length is too small to hold Buffer data");
ic_logger_msg!(logger, "Max data length is too small to hold Buffer data");
return Err(InstructionError::AccountDataTooSmall);
}
@ -408,7 +394,7 @@ fn process_loader_upgradeable_instruction(
let (derived_address, bump_seed) =
Pubkey::find_program_address(&[program.unsigned_key().as_ref()], &program_id);
if derived_address != *programdata.unsigned_key() {
log!(logger, "ProgramData address is not derived");
ic_logger_msg!(logger, "ProgramData address is not derived");
return Err(InstructionError::InvalidArgument);
}
@ -459,7 +445,7 @@ fn process_loader_upgradeable_instruction(
payer.try_account_ref_mut()?.lamports += buffer.lamports()?;
buffer.try_account_ref_mut()?.lamports = 0;
log!(logger, "Deployed program {:?}", program.unsigned_key());
ic_logger_msg!(logger, "Deployed program {:?}", program.unsigned_key());
}
UpgradeableLoaderInstruction::Upgrade => {
let programdata = next_keyed_account(account_iter)?;
@ -473,17 +459,17 @@ fn process_loader_upgradeable_instruction(
// Verify Program account
if !program.executable()? {
log!(logger, "Program account not executable");
ic_logger_msg!(logger, "Program account not executable");
return Err(InstructionError::AccountNotExecutable);
}
if !program.is_writable()
&& invoke_context.is_feature_active(&prevent_upgrade_and_invoke::id())
{
log!(logger, "Program account not writeable");
ic_logger_msg!(logger, "Program account not writeable");
return Err(InstructionError::InvalidArgument);
}
if &program.owner()? != program_id {
log!(logger, "Program account not owned by loader");
ic_logger_msg!(logger, "Program account not owned by loader");
return Err(InstructionError::IncorrectProgramId);
}
if let UpgradeableLoaderState::Program {
@ -491,11 +477,11 @@ fn process_loader_upgradeable_instruction(
} = program.state()?
{
if programdata_address != *programdata.unsigned_key() {
log!(logger, "Program and ProgramData account mismatch");
ic_logger_msg!(logger, "Program and ProgramData account mismatch");
return Err(InstructionError::InvalidArgument);
}
} else {
log!(logger, "Invalid Program account");
ic_logger_msg!(logger, "Invalid Program account");
return Err(InstructionError::InvalidAccountData);
}
@ -506,7 +492,7 @@ fn process_loader_upgradeable_instruction(
} = buffer.state()?
{
} else {
log!(logger, "Invalid Buffer account");
ic_logger_msg!(logger, "Invalid Buffer account");
return Err(InstructionError::InvalidArgument);
}
@ -518,18 +504,18 @@ fn process_loader_upgradeable_instruction(
if buffer.data_len()? < UpgradeableLoaderState::buffer_data_offset()?
|| buffer_data_len == 0
{
log!(logger, "Buffer account too small");
ic_logger_msg!(logger, "Buffer account too small");
return Err(InstructionError::InvalidAccountData);
}
// Verify ProgramData account
if programdata.data_len()? < UpgradeableLoaderState::programdata_len(buffer_data_len)? {
log!(logger, "ProgramData account not large enough");
ic_logger_msg!(logger, "ProgramData account not large enough");
return Err(InstructionError::AccountDataTooSmall);
}
if programdata.lamports()? + buffer.lamports()? < programdata_balance_required {
log!(logger, "Buffer account balance too low to fund upgrade");
ic_logger_msg!(logger, "Buffer account balance too low to fund upgrade");
return Err(InstructionError::InsufficientFunds);
}
if let UpgradeableLoaderState::ProgramData {
@ -538,19 +524,19 @@ fn process_loader_upgradeable_instruction(
} = programdata.state()?
{
if upgrade_authority_address == None {
log!(logger, "Program not upgradeable");
ic_logger_msg!(logger, "Program not upgradeable");
return Err(InstructionError::Immutable);
}
if upgrade_authority_address != Some(*authority.unsigned_key()) {
log!(logger, "Incorrect upgrade authority provided");
ic_logger_msg!(logger, "Incorrect upgrade authority provided");
return Err(InstructionError::IncorrectAuthority);
}
if authority.signer_key().is_none() {
log!(logger, "Upgrade authority did not sign");
ic_logger_msg!(logger, "Upgrade authority did not sign");
return Err(InstructionError::MissingRequiredSignature);
}
} else {
log!(logger, "Invalid ProgramData account");
ic_logger_msg!(logger, "Invalid ProgramData account");
return Err(InstructionError::InvalidAccountData);
}
@ -587,7 +573,7 @@ fn process_loader_upgradeable_instruction(
buffer.try_account_ref_mut()?.lamports = 0;
programdata.try_account_ref_mut()?.lamports = programdata_balance_required;
log!(logger, "Upgraded program {:?}", program.unsigned_key());
ic_logger_msg!(logger, "Upgraded program {:?}", program.unsigned_key());
}
UpgradeableLoaderInstruction::SetAuthority => {
let account = next_keyed_account(account_iter)?;
@ -599,15 +585,15 @@ fn process_loader_upgradeable_instruction(
match account.state()? {
UpgradeableLoaderState::Buffer { authority_address } => {
if authority_address == None {
log!(logger, "Buffer is immutable");
ic_logger_msg!(logger, "Buffer is immutable");
return Err(InstructionError::Immutable);
}
if authority_address != Some(*present_authority.unsigned_key()) {
log!(logger, "Incorrect buffer authority provided");
ic_logger_msg!(logger, "Incorrect buffer authority provided");
return Err(InstructionError::IncorrectAuthority);
}
if present_authority.signer_key().is_none() {
log!(logger, "Buffer authority did not sign");
ic_logger_msg!(logger, "Buffer authority did not sign");
return Err(InstructionError::MissingRequiredSignature);
}
account.set_state(&UpgradeableLoaderState::Buffer {
@ -619,15 +605,15 @@ fn process_loader_upgradeable_instruction(
upgrade_authority_address,
} => {
if upgrade_authority_address == None {
log!(logger, "Program not upgradeable");
ic_logger_msg!(logger, "Program not upgradeable");
return Err(InstructionError::Immutable);
}
if upgrade_authority_address != Some(*present_authority.unsigned_key()) {
log!(logger, "Incorrect upgrade authority provided");
ic_logger_msg!(logger, "Incorrect upgrade authority provided");
return Err(InstructionError::IncorrectAuthority);
}
if present_authority.signer_key().is_none() {
log!(logger, "Upgrade authority did not sign");
ic_logger_msg!(logger, "Upgrade authority did not sign");
return Err(InstructionError::MissingRequiredSignature);
}
account.set_state(&UpgradeableLoaderState::ProgramData {
@ -636,12 +622,12 @@ fn process_loader_upgradeable_instruction(
})?;
}
_ => {
log!(logger, "Account does not support authorities");
ic_logger_msg!(logger, "Account does not support authorities");
return Err(InstructionError::InvalidAccountData);
}
}
log!(logger, "New authority {:?}", new_authority);
ic_logger_msg!(logger, "New authority {:?}", new_authority);
}
}
@ -655,18 +641,20 @@ fn process_loader_instruction(
invoke_context: &mut dyn InvokeContext,
use_jit: bool,
) -> Result<(), InstructionError> {
let logger = invoke_context.get_logger();
let account_iter = &mut keyed_accounts.iter();
let program = next_keyed_account(account_iter)?;
if program.owner()? != *program_id {
log!(logger, "Executable account not owned by the BPF loader");
ic_msg!(
invoke_context,
"Executable account not owned by the BPF loader"
);
return Err(InstructionError::IncorrectProgramId);
}
match limited_deserialize(instruction_data)? {
LoaderInstruction::Write { offset, bytes } => {
if program.signer_key().is_none() {
log!(logger, "Program account did not sign");
ic_msg!(invoke_context, "Program account did not sign");
return Err(InstructionError::MissingRequiredSignature);
}
write_program_data(
@ -678,7 +666,7 @@ fn process_loader_instruction(
}
LoaderInstruction::Finalize => {
if program.signer_key().is_none() {
log!(logger, "key[0] did not sign the transaction");
ic_msg!(invoke_context, "key[0] did not sign the transaction");
return Err(InstructionError::MissingRequiredSignature);
}
@ -689,7 +677,11 @@ fn process_loader_instruction(
use_jit,
)?;
program.try_account_ref_mut()?.executable = true;
log!(logger, "Finalized account {:?}", program.unsigned_key());
ic_msg!(
invoke_context,
"Finalized account {:?}",
program.unsigned_key()
);
}
}
@ -757,7 +749,7 @@ impl Executor for BPFExecutor {
) {
Ok(info) => info,
Err(e) => {
log!(logger, "Failed to create BPF VM: {}", e);
ic_logger_msg!(logger, "Failed to create BPF VM: {}", e);
return Err(InstructionError::ProgramEnvironmentSetupFailure);
}
};
@ -771,7 +763,7 @@ impl Executor for BPFExecutor {
vm.execute_program_interpreted(&mut instruction_meter)
};
let after = compute_meter.borrow().get_remaining();
log!(
ic_logger_msg!(
logger,
"Program {} consumed {} of {} compute units",
program_id,
@ -787,13 +779,13 @@ impl Executor for BPFExecutor {
}
}
Err(error) => {
log!(logger, "Program {} BPF VM error: {}", program_id, error);
ic_logger_msg!(logger, "Program {} BPF VM error: {}", program_id, error);
let error = match error {
EbpfError::UserError(BPFError::SyscallError(
SyscallError::InstructionError(error),
)) => error,
err => {
log!(logger, "Program failed to complete: {:?}", err);
ic_logger_msg!(logger, "Program failed to complete: {:?}", err);
InstructionError::ProgramFailedToComplete
}
};

View File

@ -65,6 +65,36 @@ pub trait InvokeContext {
fn get_account(&self, pubkey: &Pubkey) -> Option<RefCell<Account>>;
}
/// Convenience macro to log a message with an `Rc<RefCell<dyn Logger>>`
#[macro_export]
macro_rules! ic_logger_msg {
($logger:expr, $message:expr) => {
if let Ok(logger) = $logger.try_borrow_mut() {
if logger.log_enabled() {
logger.log($message);
}
}
};
($logger:expr, $fmt:expr, $($arg:tt)*) => {
if let Ok(logger) = $logger.try_borrow_mut() {
if logger.log_enabled() {
logger.log(&format!($fmt, $($arg)*));
}
}
};
}
/// Convenience macro to log a message with an `InvokeContext`
#[macro_export]
macro_rules! ic_msg {
($invoke_context:expr, $message:expr) => {
$crate::ic_logger_msg!($invoke_context.get_logger(), $message)
};
($invoke_context:expr, $fmt:expr, $($arg:tt)*) => {
$crate::ic_logger_msg!($invoke_context.get_logger(), $fmt, $($arg)*)
};
}
#[derive(Clone, Copy, Debug, AbiExample)]
pub struct BpfComputeBudget {
/// Number of compute units that an instruction is allowed. Compute units
@ -194,11 +224,7 @@ pub mod stable_log {
program_id: &Pubkey,
invoke_depth: usize,
) {
if let Ok(logger) = logger.try_borrow_mut() {
if logger.log_enabled() {
logger.log(&format!("Program {} invoke [{}]", program_id, invoke_depth));
}
}
ic_logger_msg!(logger, "Program {} invoke [{}]", program_id, invoke_depth);
}
/// Log a message from the program itself.
@ -207,11 +233,7 @@ pub mod stable_log {
/// "Program log: <program-generated output>"
/// That is, any program-generated output is guaranteed to be prefixed by "Program log: "
pub fn program_log(logger: &Rc<RefCell<dyn Logger>>, message: &str) {
if let Ok(logger) = logger.try_borrow_mut() {
if logger.log_enabled() {
logger.log(&format!("Program log: {}", message))
}
}
ic_logger_msg!(logger, "Program log: {}", message);
}
/// Log successful program execution.
@ -219,11 +241,7 @@ pub mod stable_log {
/// The general form is:
/// "Program <address> success"
pub fn program_success(logger: &Rc<RefCell<dyn Logger>>, program_id: &Pubkey) {
if let Ok(logger) = logger.try_borrow_mut() {
if logger.log_enabled() {
logger.log(&format!("Program {} success", program_id));
}
}
ic_logger_msg!(logger, "Program {} success", program_id);
}
/// Log program execution failure
@ -235,11 +253,7 @@ pub mod stable_log {
program_id: &Pubkey,
err: &InstructionError,
) {
if let Ok(logger) = logger.try_borrow_mut() {
if logger.log_enabled() {
logger.log(&format!("Program {} failed: {}", program_id, err));
}
}
ic_logger_msg!(logger, "Program {} failed: {}", program_id, err);
}
}