Open zoedberg opened 1 month ago
zoedberg
commented
1 month ago I'm not sure this is helpful but I've noticed a strange thing: before rebasing this PR the CI was succeeding https://github.com/RGB-WG/rgb-tests/actions/runs/10809438685/job/29984552488
By running the test locally it always failed though, so I'm not sure it was just a strange behavior from the CI or if it means the error is not deterministic
dr-orlovsky
commented
1 month ago I did cargo update + changed some of submodules to develop branches. I have also added some debugging to the helper functions - but nothing which can affect the test. Nevertheless, the test now passes - as can be seen for instance here in CI: https://github.com/RGB-WG/rgb-tests/actions/runs/10905019728/job/30262854607?pr=9#step:5:298
I assume something in dependencies were broken. Let's use this PR to fix the broken dependency
UPD: The test fails on CI but always succeeds locally
dr-orlovsky
commented
1 month ago The test contain an issue: when I save the consignment I see that wlt1 on a third payment doesn't see payment1 as mined, and thus pays from the genesis. Somehow mining is not always happening; that was the reason why tests were passing before - and still sometimes non-deterministically pass
dr-orlovsky
commented
1 month ago It might be that the issue is this one: https://github.com/RGB-WG/rgb-std/issues/270
zoedberg
commented
1 month ago The test contain an issue: when I save the consignment I see that wlt1 on a third payment doesn't see payment1 as mined, and thus pays from the genesis. Somehow mining is not always happening; that was the reason why tests were passing before - and still sometimes non-deterministically pass
No, this is not the reason of undeterminism of that test. I've added a commit here that proves the test fails even if the mining method makes sure the TX gets included in a block
dr-orlovsky
commented
1 month ago I've added a commit here that proves the test fails even if the mining method makes sure the TX gets included in a block
No, I am talking not about the test failure, but about success. The test succeeds and not all of txes are mined.
zoedberg
commented
1 month ago The test with the added code (which adds mine_tx) still has a non-deterministic behavior, even when it runs alone. Therefore the non-determininsm is not due to the test but to something else. I think we should determine what is causing this before merging the PR that fixes it (https://github.com/RGB-WG/rgb-std/pull/272). The reason for the non-determinism must be in one of the lines removed/changed by that PR
dr-orlovsky
commented
1 month ago I read your comment after seeing your ACK on the other PR and merging it...
Also I do not know why github auto-closed this PR!
dr-orlovsky
commented
1 month ago Therefore the non-determininsm is not due to the test but to something else. I think we should determine what is causing this before merging the PR that fixes it (RGB-WG/rgb-std#272). The reason for the non-determinism must be in one of the lines removed/changed by that PR
The non-determinism is about txes being not mined. I do not see how this can be related to the rgb code... RGB std doesn't touch indexers neither sign nor broadcasts transactions
dr-orlovsky
commented
1 month ago In https://github.com/RGB-WG/rgb-std/pull/272#pullrequestreview-2315410410 you say:
I've run the test in https://github.com/RGB-WG/rgb-tests/pull/6 100 times and can confirm the test passed every time, so with this PR there is no more a non-deterministic behavior and transfers spending both tapret and opret allocations work again.
Here you say:
The test with the added code (which adds mine_tx) still has a non-deterministic behavior, even when it runs alone.
So which of these statements is the latest one?
The problem I see is the fact that somehow wlt_1 doesn't get the first payment mined - and it seems this happens in a non-deterministic way. It may be like that for dozens of runs in a row - and than it switches back to mining it. This was the case even before PR https://github.com/RGB-WG/rgb-std/pull/272 was opened, so this is unrelated to it. Also, the only business logic changes in that PR are https://github.com/RGB-WG/rgb-std/pull/272/commits/d28d7e64a0c08d323f1a9a0befd3f47d8d89c3c9 and https://github.com/RGB-WG/rgb-std/pull/272/commits/4c84a0ababc5642cda5d98e055590df128437e1e which are easy to verify and which do not touch anything wallet- or transaction-related. The last commit fc20101b8f947089a2d3a0740d77976b122330f2 is verbose, but it just removes unused code and some cycles, and failed mining was experienced by me before it was added
zoedberg
commented
1 month ago The non-determinism is about txes being not mined. I do not see how this can be related to the rgb code... RGB std doesn't touch indexers neither sign nor broadcasts transactions
The fact that the test passes every time with the fixing PR (https://github.com/RGB-WG/rgb-std/pull/272) included while the exact same test is non-deterministic without the fixing PR to me is a proof that the non-deterministic behavior is not caused by the test but by the PR.
The mine_tx method makes sure that TXs broadcasted by the test are mined.
If you still think the non-determinism of the test outcome comes from a mining issue, please show that there's actually an unmined test-related TX by adding assertions to the code.
So which of these statements is the latest one?
The test with the fix always passes. The same test without the fix sometimes passes and sometimes doesn't.
The problem I see is the fact that somehow wlt_1 doesn't get the first payment mined - and it seems this happens in a non-deterministic way. It may be like that for dozens of runs in a row - and than it switches back to mining it. This was the case even before PR RGB-WG/rgb-std#272 was opened, so this is unrelated to it. Also, the only business logic changes in that PR are RGB-WG/rgb-std@d28d7e6 and RGB-WG/rgb-std@4c84a0a which are easy to verify and which do not touch anything wallet- or transaction-related. The last commit fc20101b8f947089a2d3a0740d77976b122330f2 is verbose, but it just removes unused code and some cycles, and failed mining was experienced by me before it was added
The fact the PR doesn't touch anything wallet- or transaction-related doesn't exclude the possibility that the code changed/removed by the PR was causing the non-determinism. As stated, if you are still convinced the non-determinism is about mining please prove it.
dr-orlovsky
commented
1 month ago The fact that the test passes every time with the fixing PR (https://github.com/RGB-WG/rgb-std/pull/272) included while the exact same test is non-deterministic without the fixing PR to me is a proof that the non-deterministic behavior is not caused by the test but by the PR.
No it doesn't prove it.
Test may remain non-deterministic. Let's say before the fixing PR there were two scenarios how it can run, A and B, and the CI runs them non-deterministically. A always fail, B always succeeds.
The PR fixes A scenario failure. Thus, test always succeeds now, while both non-deterministic scenarios are still there.
The test with the fix always passes. The same test without the fix sometimes passes and sometimes doesn't.
So this doesn't demonstrate that non-determinism is gone: see the explanation above.
If you still think the non-determinism of the test outcome comes from a mining issue, please show that there's actually an unmined test-related TX by adding assertions to the code.
Well, I have seen that wlt_1 spends the same output in payment 3 as it spends in payment 1, so the transaction is missed. I see it from YAML output of the consignment - and the wlt_2 accepts it! This scenario was making the test succeeding for me locally before the fixing PR, which I reported to you in telegram. You wasn't able to reproduce that success, but you haven't tried according to yourself.
After the PR I still see in the YAML just one transaction in the history instead of the three. Thus, the scenario B with no payment 1 happening is still there; it is just the fact that PR fixes scenario A makes test to always succeed.
As stated, if you are still convinced the non-determinism is about mining please prove it.
It is not about being convienced; there is just no other options taking the facts into the account:
So the problem for non-determinism is somewhere in this specific test function. There could be no other logical conclusion.
zoedberg
commented
1 month ago I dug deeper, in order to find what was causing the non-deterministic outcome of the test. The TX was expected to be confirmed, since the code mines until the broadcasted TX is seen as such:
let mut attempts = 10;
loop {
mine(resume);
if self.get_tx_height(txid).is_some() {
break;
}
attempts -= 1;
if attempts == 0 {
panic!("TX is not getting mined");
}
}A deeper inspection confirms that the issue was not with TX mining as you instead thought.
Comparing a successful test run to a failing one what I see is:
match self.resolver.resolve_pub_witness(witness_id) is processing the TX from the 3rd transfer (the last one). The reason it goes into the branch that adds the AnchorMethodMismatch failure is that the anchor has a dbc_proof of type DbcProof::Tapret but close_method is OpretFirstdbc_proof of type DbcProof::Tapret and close_method is TapretFirstThis discrepancy clearly doesn't come from the TX not being confirmed.
Therefore, I continued debugging and what I found is that the non-deterministic behavior of the test was due to a different order in the calls to self.terminal_index.insert(*seal, opout)?; (here). More specifically, in both the fail and success cases this gets called twice with the same seal but different opout, with the difference that in the failing case it first gets called with an opout associated to a tapret bundle and then with an opret one, while in the succeeding case it first gets called with an opout associated to an opret bundle and then with a tapret one. So in both cases one opout would get lost, even though in the succeding case the validation code wasn't detecting the error. The specific reason for this non-deterministic behavior is in the way the bundles that get inserted in the Fascia are collected: by defining the input_map as a HashMap (here) its elements will be ordered by their hashes and not by their keys (which instead would happen by using a BTreeMap). To double-check this, you can checkout this commit, update the submodules (to checkout the only required change) and run for i in $(seq 1 100); do echo "run $i"; cargo test --test transfers tapret_wlt_receiving_opret || break; done to see that by just changing that HashMap to a BTreeMap the test always succeeds.
Debugging this in depth allowed me to understand that the succeeding case was not actually succeeding and therefore that the test was not complete enough. So I've added a 4th and 5th transfers to this PR, that now make the test always fail.
On top of this PR, I re-checked the fix in https://github.com/RGB-WG/rgb-std/pull/272 and it seems we still have a bug. Check this branch to see it yourself. Therefore I've just opened a new issue https://github.com/RGB-WG/rgb-std/issues/275 to tackle this.
dr-orlovsky
commented
1 month ago Comparing a successful test run to a failing one what I see is: This discrepancy clearly doesn't come from the TX not being confirmed.
I was not talking about that. I am talking about completely different thing.
Please just use the fixed branches which do not ever fail. Than check what you see in the YAML of consignments and you will see the tx is not mined (the last consignment has just one witness!). For a bunch of times (>dozen). Than it appears there (now you will see three witnesses in the last consignment) - for another dozen of times. In both cases the test succeeds. What switches this is not clear.
This shows that the test runs and succeeds, but its execution path is non-deterministic and somehow transaction is missed.
What you checked is that you confirmed that there is a bug with anchors which was fixed - yes, we already know that. But it is unrelated to the problem I am talking about.
zoedberg
commented
1 month ago I haven't seen the behavior you reported and I don't understand how a TX could not get mined. Please prove what you're saying by adding some assertions to the code because it's important to understand if tests are really bugged or if there are other non-deterministic behaviors in RGB (other than the one I've just proved).
dr-orlovsky
commented
1 month ago I haven't seen the behavior you reported and I don't understand how a TX could not get mined.
Yes, I was trying to explain the problem of this non-determinism in tx mining since a week but it seems I have failed all the time.
Please prove what you're saying by adding some assertions to the code because it's important to understand if tests are really bugged or if there are other non-deterministic behaviors in RGB (other than the one I've just proved).
I do not know the codebase structure well enough to understand which assertions have to be added and where - so the only way how I can "prove" this is to propose you to look into the YAML consignments after multiple test runs (the way I did it myself)
zoedberg
commented
1 month ago Yes, I was trying to explain the problem of this non-determinism in tx mining since a week but it seems I have failed all the time.
We always discussed (both here and in private messages) about non-determinism in the context of the test that was sometimes failing and sometimes succeeding. For example here you said:
Somehow mining is not always happening; that was the reason why tests were passing before - and still sometimes non-deterministically pass
So yes, communication failed. Anyway we need to make sure there are no more non-deterministic behaviors, both in the tests and in RGB code.
I do not know the codebase structure well enough to understand which assertions have to be added and where - so the only way how I can "prove" this is to propose you to look into the YAML consignments after multiple test runs (the way I did it myself)
I've looked at consignments several times while I was debugging and I've never seen what you're describing. Anyway, since statements like this needs to be demonstrated with code, I've added some assertions to the test to check the expected number of bundles and terminals in the consignment.
The result was quite unexpected:
input_map from a HashMap to a BTreeMap) they always pass, so there isn't a non-deterministic behavior. To check this yourself you can checkout to https://github.com/zoedberg/rgb-tests/tree/tapret_wlt_receiving_opret_deterministic and run for i in $(seq 1 100); do echo "run $i"; cargo test --test transfers tapret_wlt_receiving_opret || break; donefor i in $(seq 1 100); do echo "run $i"; cargo test --test transfers tapret_wlt_receiving_opret || break; done. In this case there is a really strange thing to notice though: I had to change the assertions to make the test pass.So, getting into details, in both tapret_wlt_receiving_opret_deterministic and tapret_wlt_receiving_opret_fix_271 the first 2 consignments pass the following assertions:
assert_eq!(consignment.bundles.len(), 1);
assert_eq!(consignment.terminals.len(), 1);assert_eq!(consignment.bundles.len(), 2);
assert_eq!(consignment.terminals.len(), 0);While for the consignment of the third transfer we have that:
tapret_wlt_receiving_opret_deterministic:
assert_eq!(consignment.bundles.len(), 2);
assert_eq!(consignment.terminals.len(), 1);tapret_wlt_receiving_opret_fix_271:
assert_eq!(consignment.bundles.len(), 0);
assert_eq!(consignment.terminals.len(), 0);Not sure this is the cause of https://github.com/RGB-WG/rgb-std/issues/275 but this definitely seems like a bug.
Anyway, to me these assertions prove there is no such case of a TX not getting mined and that the only non-deterministic behavior was in input_map being a HashMap. Do you agree with this or think I should add more assertions?
dr-orlovsky
commented
1 month ago The problem I witnessed is the following: there are two scenarios in which test runs. The scenarios are following: 1) normal scenario, all transaction mined; 2) scenario where transactions in this specific test are not mined and YAML of consignment spend directly from genesis in the third transaction
Before https://github.com/RGB-WG/rgb-std/pull/272 (1) was failing and (2) was suceeding (you haven't witnessed that, but I had and reported you in telegram private messages before doing PR 272). After PR 272 both scenarios become succeeding, but they both are still there (that is what I meant "the non-determinism was there before and is still there, even though the test succeeds").
The strangest part is that test stays on one of the scenarios for ~10-20 runs in a raw, and then "switches" to another scenario, stays there for another ~20 runs, switches back and so on. So this is undetectable with a CI which does just a single run. You need to run many-many times and than eventually you will witness the switch.
I have broken my head trying to understand how that can be possible and how to hunt this issue down. I have no suggestions which additonal assetions are required - I will look much more into the new code you've done over the weekend, run it on the server for hundred times and will hunt for the assertions fired.
dr-orlovsky
commented
1 month ago consignment 3 in tapret_wlt_receiving_opret_fix_271:assert_eq!(consignment.bundles.len(), 0); assert_eq!(consignment.terminals.len(), 0);
Basically this seems to be the bug I am talking about: sometimes the third consignment spends genesis, not seeing the previous transactions!
The fact that it doesn't happen all the time. I see you run the first test for 100 times, but you fail on the first assertion. Try to run it on different days and record how many transactions the consignment has in the third transfer - and you will see the two scenarious I am talking about. The same thing should be true also without https://github.com/RGB-WG/rgb-std/issues/275 - I just assume you need to wait some time before runs (few hrs? I do not know).
I can't imagine what can influence that thing. Maybe stopping docker containers and starting them again...
zoedberg
commented
1 month ago I've opened https://github.com/RGB-WG/rgb-tests/pull/16 with the tapret_wlt_receiving_opret_fix_271 branch, where I also added a CI job to run the test 100 times. This way we can run it several times, in different hours and on different days to see if the behavior is deterministic or not. I expect it to have a deterministic behavior but I think this is the only way to prove it.
dr-orlovsky
commented
1 month ago This way we can run it several times, in different hours and on different days to see if the behavior is deterministic or not.
So assertions on the number of bundles in the last transfer + 100 times + running different times should work, yes
zoedberg
commented
1 month ago So assertions on the number of bundles in the last transfer + 100 times + running different times should work, yes
I've ran the tests of https://github.com/RGB-WG/rgb-tests/pull/16 several times on the CI on different days/hours and as you can see they always passed. So can we now agree the tests have a deterministic behavior?
dr-orlovsky
commented
1 month ago The problem with determinism is that it can't be proven through tests: only formally. So for now I agree that we do not have a replicate non-deterministic behavior. But I won't feel safe until I will find out what I was experiencing in the past and why it has gone.
BTW introduction of nix builds should really help with determinism. However I have zero experience with it - nor time to understand how to use it. So maybe we will leave that to the future
zoedberg
commented
1 month ago But I won't feel safe until I will find out what I was experiencing in the past and why it has gone.
Is it possible that you were checking the wrong consignments? I mean, it's really hard to believe that without changing the code a non-deterministic behavior became deterministic out of the blue.
BTW introduction of nix builds should really help with determinism. However I have zero experience with it - nor time to understand how to use it. So maybe we will leave that to the future
I'm not sure about this. IMO the system determinism shouldn't affect the deterministic (or non-deterministic) behavior of a test. Also in a real world scenario users usually don't use nix, so IMO it's better to run tests in widely used systems
dr-orlovsky
commented
1 month ago Is it possible that you were checking the wrong consignments?
I run just one test, and checked all produced consignments, so very low probability
I mean, it's really hard to believe that without changing the code a non-deterministic behavior became deterministic out of the blue.
That what surprises me and I am tend to believe that this is something with how mining works in dockerized environments on different platforms and in different server restarts. Nix fixes this
I'm not sure about this. IMO the system determinism shouldn't affect the deterministic (or non-deterministic) behavior of a test.
From what I know it is actually one of the main reasons for the non-determinisim --- and the reason why Nix and Guix were created first hand
Also in a real world scenario users usually don't use nix, so IMO it's better to run tests in widely used systems
We need both
zoedberg
commented
1 month ago I run just one test, and checked all produced consignments, so very low probability
There are 2 wallets and 3 consignments involved, so I don't think the probability is so low. Also, speaking about probabilities, what is more likely? A human error or a software bug that only shows up on your machine? Also, to get a better picture now that we have the asserts, does the test in #16 pass every time on the machine where you've seen the non-deterministic behavior?
That what surprises me and I am tend to believe that this is something with how mining works in dockerized environments on different platforms and in different server restarts. Nix fixes this
Docker creates an environment that basically only shares the kernel with the host system, with all other components built deterministically and in a reproducible way, which is why one of its main uses is to have the same behavior between development, test and production systems. Nix does something similar, with one of its advantages being the ability to roll-back changes to system configuration if something goes wrong, but that's not useful in this context. All in all, I fail to see the difference between Docker and Nix in this context and expect Docker to do a perfect job in isolating differences across systems.
From what I know it is actually one of the main reasons for the non-determinisim --- and the reason why Nix and Guix were created first hand
No, this is not the reason Nix was created. It was created to address challenges in software package management, reproducibility, and system configuration. So its purpose is for system determinism, not for test determinism.
We need both
It makes sense to have both. We have Docker to get a reproducible testing environment, that can be reproduced in CI and locally. We can run tests in different conditions and on different machines, and we already do. It's just that when reporting an issue it makes more sense to have it as reproducible as possible to reduce the debugging effort. Anyway I don't see this as a priority and I don't think this is the right place where we should discuss nix, since as I'm trying to explain and prove the main point here is that there isn't any non-deterministic behavior in the tests. And to convince myself that I'm wrong I need to see the tests in #16 fail at least once. If you're convinced that running the tests on Nix would highlight the non-deterministic behavior of the tests feel free to add Nix to #16 or open a similar PR to prove it.
dr-orlovsky
commented
1 month ago If you are convinced, than there is no issue, since I have no time or desire for re-convincing you in something you are sure. Since you are convinced and there is nothing to do, we can close this now, right?
zoedberg
commented
1 month ago If you are convinced, than there is no issue, since I have no time or desire for re-convincing you in something you are sure
Now that #16 shows the behavior to be deterministic I am convinced, unless you show some new results that tell otherwise. I would be happier if you were now convinced as well, or provided some new data that can let us move forward in the debugging.
Since you are convinced and there is nothing to do, we can close this now, right?
This PR cannot be closed since the 4th transfer of the test is failing and the "fixing" PR (https://github.com/RGB-WG/rgb-std/pull/272) produces a wrong consignment on the 3rd transfer. Therefore this needs to stay open until https://github.com/RGB-WG/rgb-std/issues/275 gets solved and a new release containing the fix will be done.
dr-orlovsky
commented
3 weeks ago I think I have found the reason there were less bundles in the consignments: https://github.com/RGB-WG/rgb-std/pull/277/commits/54f19cda814e307ff16e09148804148e74478d48#diff-59abbfa17998502bbb68f7980e463575b31ddeba39bd9f0635ac812575f7013bR1514-R1522
That fragment was removing terminal if there were more than one bundle per witness - which was the case for tapret/opret combined transfer. That's why the consignment was missing the bundles. And yes, transfer with missing bundles were succeeding since it was not invalid; and there are no checks on whether the assets are really moved with the transfer (except attempt to spend them later).
To be merged once we have a fix for this. Run
cargo test tapret_wlt_receiving_opretto see the issue:i.e.
wlt_2considers the consignment (created bywlt_1) invalid, the sender is trying to spend opret and tapret allocations together. This issue is similar to https://github.com/RGB-WG/rgb-std/issues/246, but there the sender was failing to make the transfer