program log pubkey as base58 (#12901)

programs/bpf/benches/bpf_loader.rs

@@ -229,8 +229,7 @@ fn bench_instruction_count_tuner(_bencher: &mut Bencher) {
     )
     .unwrap();
 
-    let r = vm.execute_program_metered(&mut serialized, &[], &[], instruction_meter.clone());
-    measure.stop();
+    let _ = vm.execute_program_metered(&mut serialized, &[], &[], instruction_meter.clone());    measure.stop();
     assert_eq!(
         0,
         instruction_meter.get_remaining(),

programs/bpf/c/src/tuner/tuner.c

@@ -12,9 +12,9 @@
 
 extern uint64_t entrypoint(const uint8_t *input) {
   SolAccountInfo ka[NUM_KA];
-  SolParameters params = (SolParameters) { .ka = ka };
+  SolParameters params = (SolParameters){.ka = ka};
   if (!sol_deserialize(input, &params, SOL_ARRAY_SIZE(ka))) {
-      return ERROR_INVALID_ARGUMENT;
+    return ERROR_INVALID_ARGUMENT;
   }
   uint8_t *val = (uint8_t *)ka[0].data;
   size_t current = 1;
@@ -35,6 +35,12 @@ extern uint64_t entrypoint(const uint8_t *input) {
     //   sol_sha256(bytes, SOL_ARRAY_SIZE(bytes), result);
     //   *val = result[0];
     // }
+
+    // // Uncomment for Pubkey logging syscall
+    // {
+    //   SolPubkey pubkey;
+    //   sol_log_pubkey(&pubkey);
+    // }
   }
   return *val;
 }

programs/bpf/rust/sysval/src/lib.rs

@@ -7,7 +7,6 @@ use solana_sdk::{
     entrypoint,
     entrypoint::ProgramResult,
     info,
-    log::Log,
     pubkey::Pubkey,
     rent,
     sysvar::{

programs/bpf_loader/src/lib.rs

@@ -612,6 +612,7 @@ mod tests {
                 sha256_byte_cost: 1,
                 max_call_depth: 20,
                 stack_frame_size: 4096,
+                log_pubkey_units: 100,
             },
             Rc::new(RefCell::new(Executors::default())),
             None,

programs/bpf_loader/src/syscalls.rs

@@ -8,7 +8,9 @@ use solana_rbpf::{
     vm::{EbpfVm, SyscallObject},
 };
 use solana_runtime::{
-    feature_set::{ristretto_mul_syscall_enabled, sha256_syscall_enabled},
+    feature_set::{
+        pubkey_log_syscall_enabled, ristretto_mul_syscall_enabled, sha256_syscall_enabled,
+    },
     message_processor::MessageProcessor,
     process_instruction::{ComputeMeter, InvokeContext, Logger},
 };
@@ -120,6 +122,18 @@ pub fn register_syscalls<'a>(
         }),
     )?;
 
+    if invoke_context.is_feature_active(&pubkey_log_syscall_enabled::id()) {
+        vm.register_syscall_with_context_ex(
+            "sol_log_pubkey",
+            Box::new(SyscallLogPubkey {
+                cost: compute_budget.log_pubkey_units,
+                compute_meter: invoke_context.get_compute_meter(),
+                logger: invoke_context.get_logger(),
+                loader_id,
+            }),
+        )?;
+    }
+
     if invoke_context.is_feature_active(&sha256_syscall_enabled::id()) {
         vm.register_syscall_with_context_ex(
             "sol_sha256",
@@ -400,6 +414,37 @@ impl SyscallObject<BPFError> for SyscallLogU64 {
     }
 }
 
+/// Log 5 64-bit values
+pub struct SyscallLogPubkey<'a> {
+    cost: u64,
+    compute_meter: Rc<RefCell<dyn ComputeMeter>>,
+    logger: Rc<RefCell<dyn Logger>>,
+    loader_id: &'a Pubkey,
+}
+impl<'a> SyscallObject<BPFError> for SyscallLogPubkey<'a> {
+    fn call(
+        &mut self,
+        pubkey_addr: u64,
+        _arg2: u64,
+        _arg3: u64,
+        _arg4: u64,
+        _arg5: u64,
+        ro_regions: &[MemoryRegion],
+        _rw_regions: &[MemoryRegion],
+    ) -> Result<u64, EbpfError<BPFError>> {
+        self.compute_meter.consume(self.cost)?;
+        let mut 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));
+        }
+        Ok(0)
+    }
+}
+
 /// Dynamic memory allocation syscall called when the BPF program calls
 /// `sol_alloc_free_()`.  The allocator is expected to allocate/free
 /// from/to a given chunk of memory and enforce size restrictions.  The
@@ -1194,6 +1239,7 @@ mod tests {
     use super::*;
     use crate::tests::{MockComputeMeter, MockLogger};
     use solana_sdk::hash::hashv;
+    use std::str::FromStr;
 
     macro_rules! assert_access_violation {
         ($result:expr, $va:expr, $len:expr) => {
@@ -1467,6 +1513,55 @@ mod tests {
         assert_eq!(log.borrow()[0], "Program log: 0x1, 0x2, 0x3, 0x4, 0x5");
     }
 
+    #[test]
+    fn test_syscall_sol_pubkey() {
+        let pubkey = Pubkey::from_str("MoqiU1vryuCGQSxFKA1SZ316JdLEFFhoAu6cKUNk7dN").unwrap();
+        let addr = &pubkey.as_ref()[0] as *const _ as u64;
+
+        let compute_meter: Rc<RefCell<dyn ComputeMeter>> =
+            Rc::new(RefCell::new(MockComputeMeter { remaining: 2 }));
+        let log = Rc::new(RefCell::new(vec![]));
+        let logger: Rc<RefCell<dyn Logger>> =
+            Rc::new(RefCell::new(MockLogger { log: log.clone() }));
+        let mut syscall_sol_pubkey = SyscallLogPubkey {
+            cost: 1,
+            compute_meter,
+            logger,
+            loader_id: &bpf_loader::id(),
+        };
+        let ro_regions = &[MemoryRegion {
+            addr_host: addr,
+            addr_vm: 100,
+            len: 32,
+        }];
+        let rw_regions = &[MemoryRegion::default()];
+
+        syscall_sol_pubkey
+            .call(100, 0, 0, 0, 0, ro_regions, rw_regions)
+            .unwrap();
+        assert_eq!(log.borrow().len(), 1);
+        assert_eq!(
+            log.borrow()[0],
+            "Program log: MoqiU1vryuCGQSxFKA1SZ316JdLEFFhoAu6cKUNk7dN"
+        );
+
+        assert_access_violation!(
+            syscall_sol_pubkey.call(
+                101, // AccessViolation
+                32, 0, 0, 0, ro_regions, rw_regions,
+            ),
+            101,
+            32
+        );
+
+        assert_eq!(
+            Err(EbpfError::UserError(BPFError::SyscallError(
+                SyscallError::InstructionError(InstructionError::ComputationalBudgetExceeded)
+            ))),
+            syscall_sol_pubkey.call(100, 32, 0, 0, 0, ro_regions, rw_regions)
+        );
+    }
+
     #[test]
     fn test_syscall_sol_alloc_free() {
         // large alloc

runtime/src/feature_set.rs

@@ -65,6 +65,10 @@ pub mod cumulative_rent_related_fixes {
     solana_sdk::declare_id!("FtjnuAtJTWwX3Kx9m24LduNEhzaGuuPfDW6e14SX2Fy5");
 }
 
+pub mod pubkey_log_syscall_enabled {
+    solana_sdk::declare_id!("MoqiU1vryuCGQSxFKA1SZ316JdLEFFhoAu6cKUNk7dN");
+}
+
 lazy_static! {
     /// Map of feature identifiers to user-visible description
     pub static ref FEATURE_NAMES: HashMap<Pubkey, &'static str> = [
@@ -83,6 +87,7 @@ lazy_static! {
         (max_program_call_depth_64::id(), "max program call depth 64"),
         (timestamp_correction::id(), "correct bank timestamps"),
         (cumulative_rent_related_fixes::id(), "rent fixes (#10206, #10468, #11342)"),
+        (pubkey_log_syscall_enabled::id(), "pubkey log syscall"),
         /*************** ADD NEW FEATURES HERE ***************/
     ]
     .iter()

runtime/src/process_instruction.rs

@@ -1,5 +1,6 @@
 use crate::feature_set::{
-    compute_budget_balancing, max_invoke_depth_4, max_program_call_depth_64, FeatureSet,
+    compute_budget_balancing, max_invoke_depth_4, max_program_call_depth_64,
+    pubkey_log_syscall_enabled, FeatureSet,
 };
 use solana_sdk::{
     account::{Account, KeyedAccount},
@@ -85,19 +86,21 @@ pub struct ComputeBudget {
     pub log_64_units: u64,
     /// Number of compute units consumed by a create_program_address call
     pub create_program_address_units: u64,
-    /// Number of compute units consumed by an invoke call (not including the cost incured by
+    /// Number of compute units consumed by an invoke call (not including the cost incurred by
     /// the called program)
     pub invoke_units: u64,
-    /// Maximum cross-program invocation depth allowed including the orignal caller
+    /// Maximum cross-program invocation depth allowed including the original caller
     pub max_invoke_depth: usize,
-    /// Base number of compute units consumed to call sha256
+    /// Base number of compute units consumed to call SHA256
     pub sha256_base_cost: u64,
-    /// Incremental number of units consumed by sha256 (based on bytes)
+    /// Incremental number of units consumed by SHA256 (based on bytes)
     pub sha256_byte_cost: u64,
     /// Maximum BPF to BPF call depth
     pub max_call_depth: usize,
     /// Size of a stack frame in bytes, must match the size specified in the LLVM BPF backend
     pub stack_frame_size: usize,
+    /// Number of compute units consumed by logging a `Pubkey`
+    pub log_pubkey_units: u64,
 }
 impl Default for ComputeBudget {
     fn default() -> Self {
@@ -119,6 +122,7 @@ impl ComputeBudget {
             sha256_byte_cost: 1,
             max_call_depth: 20,
             stack_frame_size: 4_096,
+            log_pubkey_units: 0,
         };
 
         if feature_set.is_active(&compute_budget_balancing::id()) {
@@ -144,6 +148,12 @@ impl ComputeBudget {
                 ..compute_budget
             };
         }
+        if feature_set.is_active(&pubkey_log_syscall_enabled::id()) {
+            compute_budget = ComputeBudget {
+                log_pubkey_units: 100,
+                ..compute_budget
+            };
+        }
         compute_budget
     }
 }

sdk/bpf/c/inc/solana_sdk.h

@@ -540,11 +540,9 @@ static uint64_t sol_invoke(
  *
  * @param key The public key to print
  */
-static void sol_log_key(const SolPubkey *key) {
-  for (int j = 0; j < sizeof(*key); j++) {
-    sol_log_64(0, 0, 0, j, key->x[j]);
-  }
-}
+void sol_log_pubkey(
+    const SolPubkey *pubkey
+);
 
 /**
  * Prints the hexadecimal representation of an array
@@ -564,7 +562,7 @@ static void sol_log_array(const uint8_t *array, int len) {
  */
 static void sol_log_params(const SolParameters *params) {
   sol_log("- Program identifier:");
-  sol_log_key(params->program_id);
+  sol_log_pubkey(params->program_id);
 
   sol_log("- Number of KeyedAccounts");
   sol_log_64(0, 0, 0, 0, params->ka_num);
@@ -574,13 +572,13 @@ static void sol_log_params(const SolParameters *params) {
     sol_log("  - Is writable");
     sol_log_64(0, 0, 0, 0, params->ka[i].is_writable);
     sol_log("  - Key");
-    sol_log_key(params->ka[i].key);
+    sol_log_pubkey(params->ka[i].key);
     sol_log("  - Lamports");
     sol_log_64(0, 0, 0, 0, *params->ka[i].lamports);
     sol_log("  - data");
     sol_log_array(params->ka[i].data, params->ka[i].data_len);
     sol_log("  - Owner");
-    sol_log_key(params->ka[i].owner);
+    sol_log_pubkey(params->ka[i].owner);
     sol_log("  - Executable");
     sol_log_64(0, 0, 0, 0, params->ka[i].executable);
     sol_log("  - Rent Epoch");

sdk/src/log.rs

@@ -2,7 +2,7 @@
 
 #![cfg(feature = "program")]
 
-use crate::{account_info::AccountInfo, pubkey::Pubkey};
+use crate::account_info::AccountInfo;
 
 /// Prints a string
 /// There are two forms and are fast
@@ -63,18 +63,6 @@ pub fn sol_log_slice(slice: &[u8]) {
     }
 }
 
-/// Prints a pubkey
-pub trait Log {
-    fn log(&self);
-}
-impl Log for Pubkey {
-    fn log(&self) {
-        for (i, k) in self.to_bytes().iter().enumerate() {
-            info!(0, 0, 0, i, *k);
-        }
-    }
-}
-
 /// Prints the hexadecimal representation of the program's input parameters
 ///
 /// @param ka - A pointer to an array of `AccountInfo` to print

sdk/src/pubkey.rs

@@ -202,9 +202,16 @@ impl Pubkey {
     pub fn to_bytes(self) -> [u8; 32] {
         self.0
     }
-}
 
-// TODO localalize this
+    /// Log a `Pubkey` from a program
+    #[cfg(feature = "program")]
+    pub fn log(&self) {
+        extern "C" {
+            fn sol_log_pubkey(pubkey_addr: *const u8);
+        };
+        unsafe { sol_log_pubkey(self.as_ref() as *const _ as *const u8) };
+    }
+}
 
 impl AsRef<[u8]> for Pubkey {
     fn as_ref(&self) -> &[u8] {