Per test timeout

[Licenser]

So this is still a draft, it adds the option to define a timeout as part of the serial test something along the lines of:

#[test]
#[serial(timeout = 600)]
fn test() -> {}

I've not added tests or documentation yet as I wanted to get feedback on if this approach is OK before putting in that work :)

[palfrey]

I like the overall approach. Couple of notes:

• Could the parameter become timeout_secs or similar? I don't like time parameters as numbers without units, as it causes confusion later on (as some users might assume msec or similar)
• If timeout cfg is not set but someone does set an explicit timeout value for a test then there should be an error (ideally compile-time) as that won't do anything I think.

[Licenser]

I'm wondering if perhaps this should remove the timeout future flag, it'd be a breaking change but that way timeout becomes optional setting (if none is given no timeout), it would reduce the configuration surface for users.

It might feel a bit odd to have tow PR's removing each other 😂 but for the sake of version progression (breaking vs non breaking changes in semver) it does make some sense to have #70 as a non breaking change, and then this as a breaking change moving more into the direction that reflects the vision of where things are going.

On the other hand there was a thought behind making it not error, mainly it allows a feature flag to quickly toggle timeouts on and off for testing with various settings, but I can totally see how hat is confusing.

[palfrey]

I'm wondering if perhaps this should remove the timeout future flag, it'd be a breaking change but that way timeout becomes optional setting (if none is given no timeout), it would reduce the configuration surface for users.

It might feel a bit odd to have tow PR's removing each other joy but for the sake of version progression (breaking vs non breaking changes in semver) it does make some sense to have #70 as a non breaking change, and then this as a breaking change moving more into the direction that reflects the vision of where things are going.

I think the timeout feature flag is maybe a semver breaking change (because anyone using default-features = no will get different behaviour). I'm currently leaning towards "get all of this in, sit on it for at least a few days just to check no-one else has anything else they haven't reported yet, then do 0.9.0" TBH v.s. any intermediate releases though!

But, back to the topic, yes, I think it makes sense to remove it. Going back to a "no timeouts" default, while permitting it getting added on a test-by-test basis is good. I suspect practically no-one uses the feature as it is released right now, and if they do, they can either not upgrade or switch to the new syntax. Also, that timeouts doesn't need any extra crates kinda leans me towards "support it for everyone".

[palfrey]

How's this going @Licenser? Any thoughts on timelines for this one?

[Licenser]

Heya,

sorry about that, I got sidetracked with 1000 other things and ended up sick the last few days :) should be able to wrap this up today or worst this week :)

[Licenser]

There we go, just needed to clean up the file_lock part. It didn't support timeouts in the past and I kept it this way but added the plumbing to add it later on if it's ever desired :).

[palfrey]

I'm happy with the implementation. It still needs docs adding for it, and at least one or two integration tests (i.e. actual uses of serial with the timeout_ms arg) before it gets merged.

Thanks!

[palfrey]

Tried adding some tests to serial_test_test/src/lib.rs of the form

    #[test]
    #[serial(timeout_key, timeout_ms = 300)]
    fn demo_timeout_with_key() {
    }

    #[test]
    #[serial(timeout_ms = 300)]
    fn demo_timeout() {
    }

and got the error expected struct `Duration`, found `u64`

[Licenser]

Darn it, I'm sorry I didn't even notice that sub project -.-, my bad, should be fixed now :)

[Licenser]

I'm confused why the tests fail at this point, I don't see a correlation to the changed code, and I can't reproduce the failures locally.

[palfrey]

I'm confused why the tests fail at this point, I don't see a correlation to the changed code, and I can't reproduce the failures locally.

Not sure. I also can't reproduce the failures locally. Possibly try bumping the timeouts to 60s just in case?

[Licenser]

Giving that a shot :)

[palfrey]

So I'm pretty sure I know what's wrong. There's a set of tests parallel_with_key_[1-3] which only work because there's at least 3 test threads. On most modern machines, this doesn't matter, as the default thread count is "number of CPUs". On Github CI, the default ends up being 1, and so I set the RUST_TEST_THREADS variable to 3 so there's enough threads. If I set that locally, I can sometimes reproduce this.

What I think is happening is that somewhere in the serial_test function wrappers, some lock is being held on when it shouldn't, and so if one of the parallel tests kicks off before the demo_timeout ones, it then blocks the demo_timeout one working (or the other two parallel ones happening) in some way. Trying to wrap my head around what's happening here exactly!

We could fix this PR by just upping the RUST_TEST_THREADS count as I'm fairly sure that'll solve the problem, but it's a hack and I'd rather get this working properly while we've got a PR that is able to clearly demonstrate the problem, even if it's got nothing to do with the work here. Just a matter of just about enough more tests added!

I'll prod at this on a new branch, but it's one of those cases that's a pain to test...

[palfrey]

I think that #72 which redoes things with dashmap might solve things. Any thoughts?

[Licenser]

I just removed the timeouts from the functions to see if the tests still fail, it looks "promising" (as in while writing this the tests are still going and not finishing). At least that's a good indication that the timeouts are not what's being off but that the breakage is linked to the number of tests - which would validate your theory.

Reading check_new_keys (both in #72 and current) I wonder if there is a logic error in the locking, I thought it's my brain not getting it - happens a lot with multithreaded locking code ;) - but I'll share it perhaps the it was onto something there.

The read_lock to check if the name is present and the write lock for inserting the name are done separately. L69 locks for reads, checks if the key is present, if not, it drops the lock in L74. In L80 it tries to take the write lock. I could see two threads slipping past the read lock and reaching the waiting for the write lock at the same time, but with entry or_default this should ™️ not be an issue.

The second thing I noticed during digging is that the timeout is only counted for how long to wait until we can enter insert into the map, not how long the test runs or am I totally misunderstanding the check_key function?

[Licenser]

We could fix this PR by just upping the RUST_TEST_THREADS count as I'm fairly sure that'll solve the problem, but it's a hack and I'd rather get this working properly while we've got a PR that is able to clearly demonstrate the problem, even if it's got nothing to do with the work here. Just a matter of just about enough more tests added!

I agree, there is no hurry to get this merged from my side, lets keep this as broken for now the hang is a bigger concern then the timeout attribute :)

[palfrey]

The read_lock to check if the name is present and the write lock for inserting the name are done separately. L69 locks for reads, checks if the key is present, if not, it drops the lock in L74. In L80 it tries to take the write lock. I could see two threads slipping past the read lock and reaching the waiting for the write lock at the same time, but with entry or_default this should tm not be an issue.

Correct. The ideal situation would be some sort of "read lock with possible upgrade to write" and most of those seem to lock it down to just one getting upgraded. The logic as it is assumes that multiple threads may indeed slip past the read lock. Only one should then get the write lock but there was some hard to test scenarios that seem to avoid this, so hence the default bits.

The second thing I noticed during digging is that the timeout is only counted for how long to wait until we can enter insert into the map, not how long the test runs or am I totally misunderstanding the check_key function?

Correct. It's original purpose was to try and catch deadlock scenarios.

See also #45 and #46 for details around both of these.

[palfrey]

Correct. The ideal situation would be some sort of "read lock with possible upgrade to write" and most of those seem to lock it down to just one getting upgraded.

To clarify: I didn't use those, as they all seemed to then cause other issues. I can't recall what offhand, but fundamentally I couldn't figure out how to use them, so this simpler setup was used.

[palfrey]

I think that #72 which redoes things with dashmap might solve things. Any thoughts?

I've merged this now. Can you resolve the conflicts here and let's see if it's still running clean and then let's get it merged.

[Licenser]

On it, fingers crossed :)

[Licenser]

It passed! Great call on the dashmap :) wooh!

[palfrey]

Released as part of 0.9.0