[consensus] Shared object transaction unit test failure

[huitseeker]

Encountered on CI of a PR modifying purely github metadata:
https://github.com/MystenLabs/sui/runs/6200152939?check_suite_focus=true

Flaky and non-reproducible.

running 2 tests
test shared_object_transaction ... ok
test call_shared_object_contract ... FAILED

failures:

---- call_shared_object_contract stdout ----
thread 'call_shared_object_contract' panicked at 'Error acquiring lock for object(s): [UnexpectedSequenceNumber { object_id: 6EE48C2E2A362479E1F5DD836BA27D48C5546E7A, expected_sequence: SequenceNumber(2), given_sequence: SequenceNumber(1) }]', sui/tests/shared_objects_tests.rs:75:30
stack backtrace:
   0: rust_begin_unwind
             at /rustc/69a6d12e9f0372e3c6d82bc7c7e410dab02d0500/library/std/src/panicking.rs:584:5
   1: core::panicking::panic_fmt
             at /rustc/69a6d12e9f0372e3c6d82bc7c7e410dab02d0500/library/core/src/panicking.rs:143:14
   2: shared_objects_tests::submit_shared_object_transaction::{{closure}}
             at ./tests/shared_objects_tests.rs:75:30
   3: <core::future::from_generator::GenFuture<T> as core::future::future::Future>::poll
             at /rustc/69a6d12e9f0372e3c6d82bc7c7e410dab02d0500/library/core/src/future/mod.rs:91:19
   4: shared_objects_tests::call_shared_object_contract::{{closure}}
             at ./tests/shared_objects_tests.rs:168:72
   5: <core::future::from_generator::GenFuture<T> as core::future::future::Future>::poll
             at /rustc/69a6d12e9f0372e3c6d82bc7c7e410dab02d0500/library/core/src/future/mod.rs:91:19
   6: <core::pin::Pin<P> as core::future::future::Future>::poll
             at /rustc/69a6d12e9f0372e3c6d82bc7c7e410dab02d0500/library/core/src/future/future.rs:124:9
   7: tokio::runtime::basic_scheduler::CoreGuard::block_on::{{closure}}::{{closure}}::{{closure}}
             at /home/ubuntu/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.17.0/src/runtime/basic_scheduler.rs:498:48
   8: tokio::coop::with_budget::{{closure}}
             at /home/ubuntu/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.17.0/src/coop.rs:102:9
   9: std::thread::local::LocalKey<T>::try_with
             at /rustc/69a6d12e9f0372e3c6d82bc7c7e410dab02d0500/library/std/src/thread/local.rs:442:16
  10: std::thread::local::LocalKey<T>::with
             at /rustc/69a6d12e9f0372e3c6d82bc7c7e410dab02d0500/library/std/src/thread/local.rs:418:9
  11: tokio::coop::with_budget
             at /home/ubuntu/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.17.0/src/coop.rs:95:5
  12: tokio::coop::budget
             at /home/ubuntu/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.17.0/src/coop.rs:72:5
  13: tokio::runtime::basic_scheduler::CoreGuard::block_on::{{closure}}::{{closure}}
             at /home/ubuntu/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.17.0/src/runtime/basic_scheduler.rs:498:25
  14: tokio::runtime::basic_scheduler::Context::enter
             at /home/ubuntu/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.17.0/src/runtime/basic_scheduler.rs:356:19
  15: tokio::runtime::basic_scheduler::CoreGuard::block_on::{{closure}}
             at /home/ubuntu/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.17.0/src/runtime/basic_scheduler.rs:497:36
  16: tokio::runtime::basic_scheduler::CoreGuard::enter::{{closure}}
             at /home/ubuntu/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.17.0/src/runtime/basic_scheduler.rs:555:57
  17: tokio::macros::scoped_tls::ScopedKey<T>::set
             at /home/ubuntu/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.17.0/src/macros/scoped_tls.rs:61:9
  18: tokio::runtime::basic_scheduler::CoreGuard::enter
             at /home/ubuntu/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.17.0/src/runtime/basic_scheduler.rs:555:27
  19: tokio::runtime::basic_scheduler::CoreGuard::block_on
             at /home/ubuntu/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.17.0/src/runtime/basic_scheduler.rs:488:9
  20: tokio::runtime::basic_scheduler::BasicScheduler::block_on
             at /home/ubuntu/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.17.0/src/runtime/basic_scheduler.rs:168:24
  21: tokio::runtime::Runtime::block_on
             at /home/ubuntu/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.17.0/src/runtime/mod.rs:475:46
  22: shared_objects_tests::call_shared_object_contract
             at ./tests/shared_objects_tests.rs:186:5
  23: shared_objects_tests::call_shared_object_contract::{{closure}}
             at ./tests/shared_objects_tests.rs:104:7
  24: core::ops::function::FnOnce::call_once
             at /rustc/69a6d12e9f0372e3c6d82bc7c7e410dab02d0500/library/core/src/ops/function.rs:[227](https://github.com/MystenLabs/sui/runs/6200152939?check_suite_focus=true#step:5:227):5
  25: core::ops::function::FnOnce::call_once
             at /rustc/69a6d12e9f0372e3c6d82bc7c7e410dab02d0500/library/core/src/ops/function.rs:227:5
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.


failures:
    call_shared_object_contract

test result: FAILED. 1 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 8.10s

error: test failed, to rerun pass '-p sui --test shared_objects_tests'
Error: Process completed with exit code 101.

Full log : https://gist.github.com/huitseeker/e5333b31a45b20fe6e56d1d6e425f78b

cc @asonnino for shared objects, @velvia for locking service.

[asonnino]

mmh that's strange. Feel free to #[ignore] the tests for now. I am working on a number of things and then I will go and fix it

[huitseeker]

Encountered once again https://github.com/MystenLabs/sui/runs/6200526155?check_suite_focus=true

[huitseeker]

And again: https://github.com/MystenLabs/sui/runs/6200654500?check_suite_focus=true

[huitseeker]

And again : https://github.com/MystenLabs/sui/runs/6200808291?check_suite_focus=true

OK,I'm unplugging it.

[huitseeker]

#1626

[asonnino]

Here is my theory of what happens (just a theory since I cannot reproduce), @huitseeker let me know if it makes sense.

The Sui authority submitted the certificate containing shared-object SO to consensus, it is then configured to wait for 1 second for the consensus' output and then abort. The reason why it does so is because a transaction submitted to consensus is not guaranteed to be eventually committed. Upon aborting, the authority tells the error to the client who re-submits the certificate (in a loop) to another authority.

The following scenario may then happen (https://github.com/MystenLabs/sui/runs/6200526155?check_suite_focus=true):

1. The client submits the certificate of transaction TX1 to authority 1 and receives a timeout message
2. The client submits the certificate of transaction TX1 to authority 2
3. In the meantime authority 1 manages to get its certificate sequenced, the tuple (TX1, SO) is thus locked for sequence number 1
4. Authority 2 manages to get its certificate sequenced, the tuple (TX1, SO) is thus locked for sequence number 2
5. Authority 2 also executes the certificate, and the client receives a success response from authority 2
6. The client submits to authority 1 a certificate of transaction TX2 that also contains the same shared object SO
7. Authority 1 manages to get the certificate sequenced, (TX2, SO) is thus locked for sequence number 3
8. Authority 1 then tries to execute the certificate but now there is the problem below:

Authority 1 did not execute TX1 (it just sequenced it), it recorded a lock of (TX1, SO) for sequence number 2 (step 4) and a lock of (TX2, SO) for sequence number 3 (step 7). It however still holds an outdated record of SO at sequence number 1 (since it did not execute any certificate). The first transaction that authority 1 expects to execute is thus TX1. The tuple (TX2, SO) was supposed to come third. So upon executing TX2, authority 1 says that TX2 was supposed to come third through the error message "expected sequence number 3 but got sequence number 1".

If step 3 did not happen in the scenario above, the error message would be "expected sequence number 2 but got sequence number 1": https://github.com/MystenLabs/sui/runs/6200808291?check_suite_focus=true

[asonnino]

The shared-object logic is not broken but the client/synchronizer has to do a lot of things to submit shared object transactions (my test client doesn't do any of it). I am now thinking about the best way to solve it (potentially by alleviating some of the load from the client).

[asonnino]

(Also the error message returned by AutorityState is not very clear)