Add tracing to PostMessage.

Change-Id: I13005cef8cc5a07021066e5182b5ad818b3be30e

solana/bridge/program/Cargo.toml

@@ -10,9 +10,10 @@ name = "bridge"
 
 [features]
 client = ["solitaire/client", "solitaire-client", "no-entrypoint"]
-no-entrypoint = ["solitaire/no-entrypoint"]
 cpi = ["no-entrypoint"]
 default = []
+no-entrypoint = ["solitaire/no-entrypoint"]
+trace = ["solitaire/trace"]
 
 [dependencies]
 borsh = "0.8.1"

solana/bridge/program/src/api/post_message.rs

@@ -18,6 +18,7 @@ use solana_program::{
 };
 use solitaire::{
     processors::seeded::Seeded,
+    trace,
     CreationLamports::Exempt,
     *,
 };
@@ -74,12 +75,17 @@ pub fn post_message(
     accs: &mut PostMessage,
     data: PostMessageData,
 ) -> Result<()> {
+    trace!("Message Address: {}", accs.message.info().key);
+
     let msg_derivation = MessageDerivationData {
         emitter_key: accs.emitter.key.to_bytes(),
         emitter_chain: 1,
         nonce: data.nonce,
         payload: data.payload.clone(),
     };
+
+    trace!("Verifying Message: {}, {}", accs.emitter.key, data.nonce,);
+
     accs.message
         .verify_derivation(ctx.program_id, &msg_derivation)?;
 
@@ -91,17 +97,25 @@ pub fn post_message(
         .ok_or(MathOverflow)?
         < accs.bridge.config.fee
     {
+        trace!(
+            "Expected fee not found: fee, last_lamports, collector: {} {} {}",
+            accs.bridge.config.fee,
+            accs.bridge.last_lamports,
+            accs.fee_collector.lamports(),
+        );
         return Err(InsufficientFees.into());
     }
     accs.bridge.last_lamports = accs.fee_collector.lamports();
 
     // Init sequence tracker if it does not exist yet.
     if !accs.sequence.is_initialized() {
+        trace!("Initializing Sequence account to 0.");
         accs.sequence
             .create(&(&*accs).into(), ctx, accs.payer.key, Exempt)?;
     }
 
     // Initialize transfer
+    trace!("Setting Message Details");
     accs.message.submission_time = accs.clock.unix_timestamp as u32;
     accs.message.emitter_chain = 1;
     accs.message.emitter_address = accs.emitter.key.to_bytes();
@@ -114,6 +128,7 @@ pub fn post_message(
         .create(&msg_derivation, ctx, accs.payer.key, Exempt)?;
 
     // Bump sequence number
+    trace!("New Sequence: {}", accs.sequence.sequence + 1);
     accs.sequence.sequence += 1;
 
     Ok(())

solana/bridge/program/src/instructions.rs

@@ -94,7 +94,7 @@ pub fn post_message(
         },
         &program_id,
     );
-    let message = Message::<'_, { AccountState::Uninitialized }>::key(
+    let message = Message::<'_, { AccountState::MaybeInitialized }>::key(
         &MessageDerivationData {
             emitter_key: emitter.to_bytes(),
             emitter_chain: 1,

solana/bridge/program/tests/common.rs

@@ -152,17 +152,14 @@ mod helpers {
     ) -> Pubkey {
         // Transfer money into the fee collector as it needs a balance/must exist.
         let fee_collector = FeeCollector::<'_>::key(None, program);
-        transfer(client, payer, &fee_collector, 100_000_000_000);
+        transfer(client, payer, &fee_collector, 10_000);
 
-        let (message_key, instruction) = instructions::post_message(*program, payer.pubkey(), emitter.pubkey(), nonce, data)
-            .unwrap();
+        // Capture the resulting message, later functions will need this.
+        let (message_key, instruction) =
+            instructions::post_message(*program, payer.pubkey(), emitter.pubkey(), nonce, data)
+                .unwrap();
 
-        execute(
-            client,
-            payer,
-            &[payer, emitter],
-            &[instruction],
-        );
+        execute(client, payer, &[payer, emitter], &[instruction]);
 
         message_key
     }
@@ -181,32 +178,34 @@ mod helpers {
             let mut signers = [-1; 19];
             signers[i] = 0;
 
-            execute(client, payer, &[payer], &vec![
-                new_secp256k1_instruction(&key, &body),
-                instructions::verify_signatures(*program, payer.pubkey(), 0, VerifySignaturesData {
-                    hash: body_hash,
-                    initial_creation: true,
-                    signers,
-                }).unwrap(),
-            ]);
+            execute(
+                client,
+                payer,
+                &[payer],
+                &vec![
+                    new_secp256k1_instruction(&key, &body),
+                    instructions::verify_signatures(
+                        *program,
+                        payer.pubkey(),
+                        0,
+                        VerifySignaturesData {
+                            hash: body_hash,
+                            initial_creation: true,
+                            signers,
+                        },
+                    )
+                    .unwrap(),
+                ],
+            );
         }
     }
 
-    pub fn post_vaa(
-        client: &RpcClient,
-        program: &Pubkey,
-        payer: &Keypair,
-        vaa: PostVAAData,
-    ) {
+    pub fn post_vaa(client: &RpcClient, program: &Pubkey, payer: &Keypair, vaa: PostVAAData) {
         execute(
             client,
             payer,
             &[payer],
-            &[instructions::post_vaa(
-                *program,
-                payer.pubkey(),
-                vaa,
-            )],
+            &[instructions::post_vaa(*program, payer.pubkey(), vaa)],
         );
     }
 
@@ -254,21 +253,12 @@ mod helpers {
         );
     }
 
-    pub fn set_fees(
-        client: &RpcClient,
-        program: &Pubkey,
-        payer: &Keypair,
-        fee: u32,
-    ) {
+    pub fn set_fees(client: &RpcClient, program: &Pubkey, payer: &Keypair, fee: u32) {
         execute(
             client,
             payer,
             &[payer],
-            &[instructions::set_fees(
-                *program,
-                payer.pubkey(),
-                fee,
-            )],
+            &[instructions::set_fees(*program, payer.pubkey(), fee)],
         );
     }