Skip to content
This repository was archived by the owner on Jan 22, 2025. It is now read-only.

RPC simulateTransaction endpoint now returns program log output #10432

Merged
merged 1 commit into from
Jun 6, 2020

Conversation

mvines
Copy link
Contributor

@mvines mvines commented Jun 5, 2020

To view program log output in the wild, the only option is to find a solana-validator log file to troll through. Not exactly friendly for a front-end program developer/user.

Instead simulateTransaction now returns all sol_log, sol_log_64 and sol_panic messages back to the user for easy viewing.

This required a touch of plumbing through bank/message_processor but InvokeContext is proving handy for more than just enabling cross-program support. In the future more debug introspection facilities could probably be plumbed in along this same path.

This PR changes the RPC simulateTransaction signature slightly, but I doubt any existing RPC users will notice/care

Fixes #10364

@mvines mvines force-pushed the logit branch 4 times, most recently from 952d8ae to 845eb2f Compare June 5, 2020 19:37
@mvines mvines requested a review from jackcmay June 5, 2020 19:44

#[derive(Default)]
pub struct LogCollector {
messages: RefCell<Vec<String>>,
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

RefCell cause passing around Option<&mut LogCollector> turns into a mess very quickly, so I acquiesced to Option<&LogCollector> with this RefCell

}

// Ignore this test: solana_logger conflicts when running tests concurrently,
// this results in the bad string length being ignored and not returning an error
#[test]
#[ignore]
#[serial]
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I tried serial for these two tests and it appeared to work but then started showing up in CI as failures...

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just noticed that CI failed on this test as expected due to conflict. Commited a change to ignore these tests again to unblock CI

Copy link
Contributor Author

@mvines mvines Jun 5, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I just reworked these tests to avoid using solana_logger::setup_with_default("solana=info"); entirely. With the MockInvokeContext, we can actually collect and validate that the log functions actually output the expected result instead

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Strange that it fails on CI but not locally, maybe the conflict is not what I thought it was

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Maybe I'm reading it wrong but doesn't MockInvokeContext still use solana_logger to determine if the log message is enabled?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sry I'm moving the furniture on you.

MockInvokeContext:

        fn log_enabled(&self) -> bool {
            true
        }
        fn log(&mut self, message: &str) {
            info!("[MockInvokeContext::log] {}", message);
            self.log.push(message.to_string());
        }

ThisInvokeContext:

    fn log_enabled(&self) -> bool {
        log_enabled!(log::Level::Info) || self.log_collector.is_some()
    }

    fn log(&mut self, message: &str) {
        info!("{}", message);
        if let Some(log_collector) = self.log_collector {
            log_collector.log(message);
        }
    }

@mvines mvines force-pushed the logit branch 3 times, most recently from 752328a to 093f495 Compare June 5, 2020 23:26
@mvines
Copy link
Contributor Author

mvines commented Jun 6, 2020

Close, just gotta make benches/bpf_loader.rs happy. Any further comments @jackcmay?

@jackcmay
Copy link
Contributor

jackcmay commented Jun 6, 2020

lgtm!

@codecov
Copy link

codecov bot commented Jun 6, 2020

Codecov Report

Merging #10432 into master will increase coverage by 0.0%.
The diff coverage is 84.9%.

@@           Coverage Diff           @@
##           master   #10432   +/-   ##
=======================================
  Coverage    81.6%    81.6%           
=======================================
  Files         295      296    +1     
  Lines       69277    69353   +76     
=======================================
+ Hits        56558    56625   +67     
- Misses      12719    12728    +9     

@mvines mvines merged commit 7e2651c into solana-labs:master Jun 6, 2020
mergify bot pushed a commit that referenced this pull request Jun 6, 2020
(cherry picked from commit 7e2651c)

# Conflicts:
#	programs/bpf/benches/bpf_loader.rs
#	programs/bpf_loader/src/lib.rs
#	programs/bpf_loader/src/syscalls.rs
#	runtime/src/bank.rs
#	runtime/src/message_processor.rs
#	sdk/src/entrypoint_native.rs
mergify bot pushed a commit that referenced this pull request Jun 6, 2020
@mvines mvines deleted the logit branch June 8, 2020 05:42
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

simulateTransaction RPC endpoint should optionally return program log output
2 participants