More logging (#217)

* Format

* CI

* Fixed

* Add comment to README

* Format config

* Fix build

* Log time and ema

* Fix ema deserialize

* Revert format

* Add expo

* Fix comments

* Unused import

Co-authored-by: Guillermo Bescos <guibescos>

program/rust/build.rs

@@ -12,6 +12,7 @@ fn main() {
     parser.register_traits("pc_acc", borsh_derives.to_vec());
     parser.register_traits("pc_price_info", borsh_derives.to_vec());
     parser.register_traits("cmd_upd_price", borsh_derives.to_vec());
+    parser.register_traits("pc_ema", borsh_derives.to_vec());
 
     //generate and write bindings
     let bindings = Builder::default()

program/rust/src/deserialize.rs

@@ -0,0 +1,36 @@
+use crate::c_oracle_header::size_t;
+use crate::error::OracleError;
+use borsh::BorshDeserialize;
+use solana_program::account_info::AccountInfo;
+use solana_program::program_error::ProgramError;
+use std::mem::size_of;
+use std::result::Result;
+
+/// Deserialize field in `source` with offset `offset`
+pub fn deserialize_single_field_from_buffer<T: BorshDeserialize>(
+    source: &[u8],
+    offset: Option<size_t>,
+) -> Result<T, ProgramError> {
+    let start: usize = offset
+        .unwrap_or(0)
+        .try_into()
+        .map_err(|_| OracleError::IntegerCastingError)?;
+
+    let res: T = T::try_from_slice(&source[start..(start + size_of::<T>())])?;
+    Ok(res)
+}
+
+/// Deserialize field in `i` rank of `accounts` with offset `offset`
+pub fn deserialize_single_field_from_account<T: BorshDeserialize>(
+    accounts: &[AccountInfo],
+    i: usize,
+    offset: Option<size_t>,
+) -> Result<T, ProgramError> {
+    Ok(deserialize_single_field_from_buffer::<T>(
+        &accounts
+            .get(i)
+            .ok_or(ProgramError::NotEnoughAccountKeys)?
+            .try_borrow_data()?,
+        offset,
+    )?)
+}

program/rust/src/error.rs

@@ -10,13 +10,15 @@ pub type OracleResult = Result<u64, ProgramError>;
 pub enum OracleError {
     /// Generic catch all error
     #[error("Generic")]
-    Generic             = 600,
+    Generic                 = 600,
     /// integer casting error
     #[error("IntegerCastingError")]
-    IntegerCastingError = 601,
+    IntegerCastingError     = 601,
     /// c_entrypoint returned an unexpected value
     #[error("UnknownCError")]
-    UnknownCError       = 602,
+    UnknownCError           = 602,
+    #[error("UnrecognizedInstruction")]
+    UnrecognizedInstruction = 603,
 }
 
 impl From<OracleError> for ProgramError {

program/rust/src/lib.rs

@@ -1,4 +1,5 @@
 mod c_oracle_header;
+mod deserialize;
 mod error;
 mod log;
 mod processor;

program/rust/src/log.rs

@@ -1,46 +1,71 @@
 use crate::c_oracle_header::*;
+use crate::deserialize::{
+    deserialize_single_field_from_account,
+    deserialize_single_field_from_buffer,
+};
 use crate::error::OracleError;
 use borsh::BorshDeserialize;
 use solana_program::account_info::AccountInfo;
+use solana_program::clock::Clock;
 use solana_program::entrypoint::ProgramResult;
 use solana_program::msg;
-use std::mem::size_of;
+use solana_program::program_error::ProgramError;
+use solana_program::sysvar::Sysvar;
 
 pub fn pre_log(accounts: &[AccountInfo], instruction_data: &[u8]) -> ProgramResult {
     msg!("Pyth oracle contract");
 
-    let instruction_header: cmd_hdr = cmd_hdr::try_from_slice(&instruction_data[..8])?;
+    let instruction_header: cmd_hdr =
+        deserialize_single_field_from_buffer::<cmd_hdr>(&instruction_data, None)?;
     let instruction_id: u32 = instruction_header
         .cmd_
         .try_into()
-        .map_err(|_| OracleError::Generic)?;
+        .map_err(|_| OracleError::IntegerCastingError)?;
+
+
     match instruction_id {
         command_t_e_cmd_upd_price | command_t_e_cmd_agg_price => {
             let instruction: cmd_upd_price = cmd_upd_price::try_from_slice(instruction_data)?;
+            // Account 1 is price_info in this instruction
+            let expo: i32 = deserialize_single_field_from_account::<i32>(
+                accounts,
+                1,
+                Some(PRICE_T_EXPO_OFFSET),
+            )?;
             msg!(
-                "UpdatePrice: publisher={:}, price_account={:}, price={:}, conf={:}, status={:}, slot={:}",
+                "UpdatePrice: publisher={:}, price_account={:}, price={:}, conf={:}, expo={:}, status={:}, slot={:}, solana_time={:}",
                 accounts.get(0)
-                .ok_or(OracleError::Generic)?.key,
+                .ok_or(ProgramError::NotEnoughAccountKeys)?.key,
                 accounts.get(1)
-                .ok_or(OracleError::Generic)?.key,
+                .ok_or(ProgramError::NotEnoughAccountKeys)?.key,
                 instruction.price_,
                 instruction.conf_,
+                expo,
                 instruction.status_,
-                instruction.pub_slot_
+                instruction.pub_slot_,
+                Clock::get()?.unix_timestamp
             );
         }
         command_t_e_cmd_upd_price_no_fail_on_error => {
             let instruction: cmd_upd_price = cmd_upd_price::try_from_slice(instruction_data)?;
+            // Account 1 is price_info in this instruction
+            let expo: i32 = deserialize_single_field_from_account::<i32>(
+                accounts,
+                1,
+                Some(PRICE_T_EXPO_OFFSET),
+            )?;
             msg!(
-                "UpdatePriceNoFailOnError: publisher={:}, price_account={:}, price={:}, conf={:}, status={:}, slot={:}",
+                "UpdatePriceNoFailOnError: publisher={:}, price_account={:}, price={:}, conf={:}, expo={:}, status={:}, slot={:}, solana_time={:}",
                 accounts.get(0)
-                .ok_or(OracleError::Generic)?.key,
+                .ok_or(ProgramError::NotEnoughAccountKeys)?.key,
                 accounts.get(1)
-                .ok_or(OracleError::Generic)?.key,
+                .ok_or(ProgramError::NotEnoughAccountKeys)?.key,
                 instruction.price_,
                 instruction.conf_,
+                expo,
                 instruction.status_,
-                instruction.pub_slot_
+                instruction.pub_slot_,
+                Clock::get()?.unix_timestamp
             );
         }
         command_t_e_cmd_add_mapping => {
@@ -73,31 +98,37 @@ pub fn pre_log(accounts: &[AccountInfo], instruction_data: &[u8]) -> ProgramResu
         }
         _ => {
             msg!("UnrecognizedInstruction");
-            return Err(OracleError::Generic.into());
+            return Err(OracleError::UnrecognizedInstruction.into());
         }
     }
     Ok(())
 }
 
 pub fn post_log(c_ret_val: u64, accounts: &[AccountInfo]) -> ProgramResult {
     if c_ret_val == SUCCESSFULLY_UPDATED_AGGREGATE {
-        let start: usize = PRICE_T_AGGREGATE_OFFSET
-            .try_into()
-            .map_err(|_| OracleError::Generic)?;
-        // We trust that the C oracle has properly checked this account
-        let aggregate_price_info: pc_price_info = pc_price_info::try_from_slice(
-            &accounts
-                .get(1)
-                .ok_or(OracleError::Generic)?
-                .try_borrow_data()?[start..(start + size_of::<pc_price_info>())],
+        // We trust that the C oracle has properly checked account 1, we can only get here through
+        // the update price instructions
+        let aggregate_price_info: pc_price_info = deserialize_single_field_from_account::<
+            pc_price_info,
+        >(
+            accounts, 1, Some(PRICE_T_AGGREGATE_OFFSET)
         )?;
+        let ema_info: pc_ema =
+            deserialize_single_field_from_account::<pc_ema>(accounts, 1, Some(PRICE_T_EMA_OFFSET))?;
+        let expo: i32 =
+            deserialize_single_field_from_account::<i32>(accounts, 1, Some(PRICE_T_EXPO_OFFSET))?;
+
         msg!(
-            "UpdateAggregate : price_account={:}, price={:}, conf={:}, status={:}, slot={:}",
-            accounts.get(1).ok_or(OracleError::Generic)?.key,
+            "UpdateAggregate : price_account={:}, price={:}, conf={:}, expo={:}, status={:}, slot={:}, solana_time={:}, ema={:}",
+            accounts.get(1)
+            .ok_or(ProgramError::NotEnoughAccountKeys)?.key,
             aggregate_price_info.price_,
             aggregate_price_info.conf_,
+            expo,
             aggregate_price_info.status_,
-            aggregate_price_info.pub_slot_
+            aggregate_price_info.pub_slot_,
+            Clock::get()?.unix_timestamp,
+            ema_info.val_
         );
     }
     Ok(())

program/rust/src/price_t_offsets.h

@@ -9,6 +9,7 @@ const size_t PRICE_T_AGGREGATE_OFFSET = offsetof(struct pc_price, agg_);
 const size_t PRICE_T_AGGREGATE_CONF_OFFSET = offsetof(struct pc_price, agg_) + offsetof(struct pc_price_info, conf_);
 const size_t PRICE_T_AGGREGATE_PRICE_OFFSET = offsetof(struct pc_price, agg_) + offsetof(struct pc_price_info, price_);
 const size_t PRICE_T_AGGREGATE_STATUS_OFFSET = offsetof(struct pc_price, agg_) + offsetof(struct pc_price_info, status_);
+const size_t PRICE_T_EMA_OFFSET = offsetof(struct pc_price, twap_);
 const size_t PRICE_T_PREV_TIMESTAMP_OFFSET = offsetof(struct pc_price, prev_timestamp_);
 const size_t PRICE_T_PREV_CONF_OFFSET = offsetof(struct pc_price, prev_conf_);
 const size_t PRICE_T_PREV_AGGREGATE_OFFSET = offsetof(struct pc_price, prev_price_);