Skip to content

fix: return logs for validator tests #109

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
wants to merge 1 commit into
base: main
Choose a base branch
from
Open

fix: return logs for validator tests #109

Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
12 changes: 12 additions & 0 deletions src/lib.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -61,6 +61,18 @@ pub fn fast_process_instruction(
}
};

#[cfg(feature = "unit_test_config")]
if matches!(
discriminator,
DlpDiscriminator::Delegate
| DlpDiscriminator::CommitState
| DlpDiscriminator::CommitStateFromBuffer
| DlpDiscriminator::Finalize
| DlpDiscriminator::Undelegate
) {
msg!("Processing instruction: {:?}", discriminator);
}
Comment on lines +64 to +74
Copy link
Contributor

@snawaz snawaz Oct 18, 2025 •
edited
Loading

Choose a reason for hiding this comment

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

Can we please simplify this by removing the whole if matches!() logic and just writing:

#[cfg(feature = "unit_test_config")]
msg!("Processing instruction: {:?}", discriminator);

And also remove the msg! line from slow_process_instruction(), so it isn’t logged twice.

However, this change will cause 4 tests to fail in this repo, since they ensure that the CU stays within specific limits ... but this innocent-looking change increases the CU by 413 units. 😄

So.. maybe we can introduce a separate feature flag.. like:

#[cfg(feature = "log-discriminator")]
msg!("Processing instruction: {:?}", discriminator);

// Or `log-testinfo` if more kinds of info are required by the tests.

… and enable it only when we actually need discriminator logs. 🤔

Copy link
Contributor

@snawaz snawaz Oct 18, 2025 •
edited
Loading

Choose a reason for hiding this comment

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

If we need this in production code, maybe we can write a more optimized log utility just to print a preformatted-discriminator and pay 114 CU instead of 413 CU.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

but this innocent-looking change increases the CU by 413 units. 😄

This shall be only in test mode, or do we deploy dlp compiled with unit_test_config ? I would think not. @GabrielePicco

I think if we can it would be better to avoid adding extra feature, unit_test_config already relates to tests and affects cu usage for example in load_program_upgrade_authority. Since its needed in validator tests only i think unit_test_config usage make sense as well, or we can rename it to test_config to avoid confusion

Copy link
Contributor Author

@taco-paco taco-paco Oct 20, 2025 •
edited
Loading

Choose a reason for hiding this comment

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

And also remove the msg! line from slow_process_instruction(), so it isn’t logged twice.

Then we would lose that log in release, while old dlp had it. Not sure if anyone rely on those logs tho @GabrielePicco.
The reason I made it this way:

  1. keep old(current) implementation intact
  2. avoid double logging
  3. enable only for tests

Copy link
Contributor

@snawaz snawaz Oct 20, 2025 •
edited
Loading

Choose a reason for hiding this comment

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

I think if we can it would be better to avoid adding extra feature, unit_test_config already relates to tests and affects cu usage for example in load_program_upgrade_authority

I suggested introducing a new flag, because otherwise the tests in this repo will continue to fail as they also ensure CUs stays within specific limits. Please check why the CI is failing!

Please see my previous comment again for the details.

Copy link
Contributor

@snawaz snawaz Oct 21, 2025 •
edited
Loading

Choose a reason for hiding this comment

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

We shouldn’t confuse testing and CU or performance measurements.

performance measurements are part of the testing as well.

The testing is not about correctness only, it is also about how quickly something works, which is why I have added this:

    const consumedLog = tx.meta.logMessages.find((m) =>
      m.includes("DELeGGvXpWV2fqJUhqcF5ZSYMS4JTLjteaAMARRSaeSh consumed")
    );
    const consumedCU = parseInt(consumedLog.split(" **").at(3));
    
    assert.isAtMost(
      consumedCU,
      18500,
      "delegate instruction must consume less than 18500"
    );

You don't call it a test?

To get better and more accurate CU, we can build it in "released" mode with unit_test_config (that is also why this flag should have minimal code under it). If not that, some other flag — either way we introduce a flag.

Copy link
Contributor

Choose a reason for hiding this comment

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

No need to make a big deal out of such a small detail.
We don’t need logs in production. We can feature-flag all logs with a “logging” feature to have more granular control. This would work for both the validator and CU tests.

I agree that the CU tests aren’t fully accurate; we can switch to something like Mollusk benchmarking
in the future, but it’s good enough for now.

Copy link
Contributor Author

@taco-paco taco-paco Oct 27, 2025 •
edited
Loading

Choose a reason for hiding this comment

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

@GabrielePicco The thing is that we connect CU measurements to unit_test_config flag, while its purely a test flag.
CU measurment assert/tests or whatever shall happen on the version that runs in production. There's no need for any extra flags when unit_test_config does the job when its used in proper context.
Whilte I agree @snawaz that asserting CU measurment is a test, using flag in this context is incorrect imo.

This is non-blocking at the moment and to do things properly I can create a separate PR that will fix issue with CUs.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

We ending up associating unit_test_config with CU measurment and any consequential changes under unit_test_config may affect CU measurments and we may to have to spawn new flags just for the sake of keeping CU measurments as expected

Copy link
Contributor Author

Choose a reason for hiding this comment

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

In case we still disagree on this matter I'd propose to discuss on the meeting


match discriminator {
DlpDiscriminator::Delegate => Some(processor::fast::process_delegate(
program_id, accounts, data,
Expand Down
Loading