Space efficient custom_panic

[LucasSte]

Problem

Our implementation of custom_panic can consume up to 25kb in contracts. This happens because it relies on the format! macro and, consequently, on std::fmt::write. They include many more functions in the contract and utilize dynamic dispatch, a technique that hinders compiler and link side optimizations for size reduction.

Summary of Changes

I implemented a new custom_panic that functions independently with only primitive (and unsafe) operations. It needs the stabilization of fmt::Arguments::as_str, which is happening in Rust 1.84 (see rust-lang/rust#132511).

Size comparison

Take this simple contract as an example:

entrypoint!(process_instruction);

fn process_instruction(
    _program_id: &Pubkey,
    accounts: &[AccountInfo],
    instruction_data: &[u8],
) -> ProgramResult {
    Ok(())
}

The binary size has whooping 17696 bytes (17kb).
The contract with an empty custom_panic function has 10336 bytes (10kb), so panic is consuming 7360 bytes.
The contract with my new implementation has 11696 bytes (11kb), so my implementation has 1360 bytes.

New error messages

The members of fmt::Arguments are all private, so I cannot build custom panic messages during runtime as Rust does (think about the error you get when you access an invalid index from a vector: we can only know the index and the vector length during execution time). These messages will be elided in the new panic implementation (see examples below). Error messages whose content is known at compile time will still be shown normally.

The formatting is also different. It is more efficient to call sol_log multiple times than to format a string.

Accessing an invalid index from a vector:

OLD:

Program log: panicked at src/lib.rs:21:13:\nindex out of bounds: the len is 44 but the index is 85034

NEW:

Program log: Panicked at: src/lib.rs:21:13

Calling unwrap on a None:

OLD:

Program log: panicked at src/lib.rs:23:15:\ncalled `Option::unwrap()` on a `None` value

NEW:

Program log: Panicked at: src/lib.rs:23:15
Program log: called `Option::unwrap()` on a `None` value

Alternative implementation

Instead of pre-allocating a vector, I can use a fixed length buffer and save even more bytes. In this case, however, I split the error in three log messages. I not sure if the experience is good in this case, and I'm looking for feedback. Please, check it at #3952. It has 1168 bytes.

[LucasSte]

I'm not yet replacing the exiting custom panic, because this new one requires Rust 1.84, which is going to be the next toolchain upgrade.

[LucasSte]

I can add some test programs with this implementation. I'm looking for early feedback now.

[febo]

I think we need to remove the "gate" on the not(feature = "custom-panic"). Since the entrypoint! macro always uses the custom_panic_default!, the only way to "disable" the default panic handler is to enable the feature "custom-panic" on the program. This would also disable the custom_panic_space_efficient! as it is.

Removing the not(feature = "custom-panic") in this case would solve this – a program can enable the "custom-panic" feature to disable the default and then use custom_panic_space_efficient!.

[LucasSte]

My idea is that the space efficient implementation will replace the existing one, once we have Rust 1.84 or higher in the platform tools.

What do you think of this?

[febo]

It looks really good.

Out of curiosity, does the space gain still happens when a program makes use of msg! with formatting arguments in other log messages? My guess is probably not, since all the code needed for format! to work will be added in the binary anyway.

[LucasSte]

It looks really good.

Out of curiosity, does the space gain still happens when a program makes use of msg! with formatting arguments in other log messages? My guess is probably not, since all the code needed for format! to work will be added in the binary anyway.

If you use msg! with something that needs formatting, you bring all the bloat again to the program. This is potentially another function I might look into for space optimization.

The initial idea is remove all the bloat we put into the contract, as custom_panic is necessary for every contract. On the other hand, developers can intentionally avoid msg! to decrease their contract's size.

[febo]

It looks really good.
Out of curiosity, does the space gain still happens when a program makes use of msg! with formatting arguments in other log messages? My guess is probably not, since all the code needed for format! to work will be added in the binary anyway.

If you use msg! with something that needs formatting, you bring all the bloat again to the program. This is potentially another function I might look into for space optimization.

The initial idea is remove all the bloat we put into the contract, as custom_panic is necessary for every contract. On the other hand, developers can intentionally avoid msg! to decrease their contract's size.

Talked to @joncinque about bringing the code from pinocchio-log to the SDK under a solana-program-log crate. It has limited support for formatting, but it might cover many use-cases so people would be able to avoid having to usemsg!.

[LucasSte]

It looks really good.
Out of curiosity, does the space gain still happens when a program makes use of msg! with formatting arguments in other log messages? My guess is probably not, since all the code needed for format! to work will be added in the binary anyway.

If you use msg! with something that needs formatting, you bring all the bloat again to the program. This is potentially another function I might look into for space optimization.
The initial idea is remove all the bloat we put into the contract, as custom_panic is necessary for every contract. On the other hand, developers can intentionally avoid msg! to decrease their contract's size.

Talked to @joncinque about bringing the code from pinocchio-log to the SDK under a solana-program-log crate. It has limited support for formatting, but it might cover many use-cases so people would be able to avoid having to usemsg!.

That would certainly be useful!

[joncinque]

I like this change a lot! It seems like there's two factors we need to consider:

• format! usage: since this is the main offender to the panic handler causing so much bloat, a panic handler that avoids format! is definitely worth adding
• allocation: this PR requires a dynamic allocation to write the filename, which some programs might want to avoid. Or if the program panics during allocation, what happens during this panic handler? I'd prefer using a large pre-allocated array for the string and truncate from the start of the string (instead of cutting off the end). That option avoids an additional syscall from Space efficient custom_panic (take 2) #3952 and the allocation. But my second choice would be this PR, rather than Space efficient custom_panic (take 2) #3952

For the first bit, I'd like to see the results with @febo's logging crate, in the hope that it simplifies this PR. And for the second bit, how about something like 200 bytes for the file name with a <truncated> indicator if needed?

[LucasSte]

I've removed the dynamic allocation and added an if-condition to truncate the filename in 200 bytes.
The example program has now 11504 bytes, so the custom_panic has 11504-10336=1168 bytes.

To indicate the truncation, I used an ellipsis string (...) because it has only three bytes and fits in a register (8 bytes). Using <truncation> instead increases the program size to 11520 bytes (and the panic to 1184 bytes). If another truncation marker makes more sense, I can change.

Now, I'll test @febo's logging function and post the results here.

[LucasSte]

I've removed the dynamic allocation and added an if-condition to truncate the filename in 200 bytes. The example program has now 11704 bytes, so the custom_panic has 11504-10336=1168 bytes.

To indicate the truncation, I used an ellipsis string (...) because it has only three bytes and fits in a register (8 bytes). Using <truncation> instead increases the program size to 11520 bytes (and the panic to 1184 bytes). If another truncation marker makes more sense, I can change.

Now, I'll test @febo's logging function and post the results here.

As an addend, we can increase the truncation limit to about 1000 bytes without any penalty in program size.

[LucasSte]

I made here an implementation for custom_panic using Pinocchio logging.

The program size is now 12448 bytes, so custom_panic has 2112 bytes.