Added prop_timeouts_enforced #3532

bolt12 · 2021-12-07T13:06:08Z

This PR adds tests for Connection Manager and Inbound Governor to check if their timeout values are being enforced.

This is important because timeouts are part of the specification and one needs to guarantee we are respecting them within certain margin of error.

ouroboros-network-framework/test/Test/Ouroboros/Network/Server2.hs

bolt12 · 2022-01-18T13:06:50Z

@coot I refactored the code as in our call. It turns out I ended up needing to be extra explicit on all the states but I think the code turned out better than the one I had!

ouroboros-network-framework/test/Test/Ouroboros/Network/Server2.hs

coot · 2022-01-20T12:54:00Z

network-mux/src/Network/Mux/Bearer/AttenuatedChannel.hs

@@ -92,6 +89,8 @@ writeQueueChannel QueueChannel { qcWrite } msg =
        Nothing -> return False
        Just q  -> writeTQueue q msg
                >> case msg of
+                      -- Match SO_LINGER set with 0 interval
+                      -- and close both ends without any handshake


I would add a todo, to simulate a lost MsgClose, this is easy to do: we need to close the write channel, without sending the MsgClose.

I'd say in a way we are already simulating this case by writing the message and not waiting on receiving some sort of Ack. Of course since this is a simulation environment we do not actually need to do much because the message doesn't go through the wire.

I'd say in a way we are already simulating this case by writing the message and not waiting on receiving some sort of Ack.

That's not right; resting a connection does not make it wait on an ack, the kernel will just forget the state of the connection when it sends the packet with RST option set. If the receiver does not get the packet it will get an error when next time it will try to send a packet (a reset will be send as a reply).

I will experiment with simulating a lost message like you suggested and see if that still passes the test. The problem before was that we were waiting for an Ack and that could take very long. Hopefully just closing and losing the MsgClose message will not delay it much

Tried it and the tests are passing 😄 I think now it simulates the LINGER option more faithfully.

ouroboros-network-framework/src/Ouroboros/Network/InboundGovernor.hs

ouroboros-network-framework/src/Ouroboros/Network/ConnectionManager/Core.hs

coot · 2022-01-20T13:04:56Z

ouroboros-network-framework/src/Ouroboros/Network/ConnectionManager/Core.hs

@@ -682,8 +687,7 @@ withConnectionManager ConnectionManagerArguments {
            -- using 'cancel' here, since we want to block until connection
            -- handler thread terminates.
            traverse_ cancel (getConnThread connState)
-          )
-          state
+          ))


would it work if we throwTo and then wait for all the threads to terminate; this would avoid calling cancel from a separate thread. The drawback is that if a connection is executing the cleanup handler, it will block for the TIME_WAIT interval.

throwTo is also possibly blocking right? waiting on the thread to actually receive the exception. So I do not think we would gain much from using throwTo.

cancel blocks until thread terminates

throwTo blocks until an exception is raised

so cancel can block for much longer than throwTo, since during TIME_WAIT interval, we will accept asynchronous exceptions (though they will be ignored). This will unblock throwTo, but not cancel.

bolt12 · 2022-01-26T08:52:42Z

We are not ignoring state' we are using it to build the trace. That's all that matters here because the inbound governor is going to die. What we had previously was a hack and I was building the trace using the empty state, with this patch it is a cleaner way to do it.

…

On Wed, 26 Jan 2022, 08:47 Marcin Szamotulski, ***@***.***> wrote: ***@***.**** commented on this pull request. ------------------------------ In ouroboros-network-framework/src/Ouroboros/Network/InboundGovernor.hs <#3532 (comment)> : > @@ -112,9 +112,10 @@ inboundGovernor trTracer tracer serverControlChannel inboundIdleTimeout (\(e :: SomeAsyncException) -> do state <- atomically $ readTVar st _ <- Map.traverseWithKey - (\connId _ -> + (\connId _ -> do + let state' = unregisterConnection connId state If we want to do that properly, we should thread the state and use Map.foldrWithKey instead, otherwise ignoring state' is just confusing. — Reply to this email directly, view it on GitHub <#3532 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AE2SULLLOHOEBXNHWBPDTELUX6YLDANCNFSM5JRGQCOQ> . You are receiving this because you authored the thread.Message ID: ***@***.***>

ouroboros-network-framework/src/Ouroboros/Network/ConnectionManager/Core.hs

bolt12 · 2022-01-26T08:59:10Z

Hmmm right, is not very faithful.

…

On Wed, 26 Jan 2022, 08:53 Marcin Szamotulski, ***@***.***> wrote: ***@***.**** commented on this pull request. ------------------------------ In network-mux/src/Network/Mux/Bearer/AttenuatedChannel.hs <#3532 (comment)> : > @@ -92,6 +89,8 @@ writeQueueChannel QueueChannel { qcWrite } msg = Nothing -> return False Just q -> writeTQueue q msg >> case msg of + -- Match SO_LINGER set with 0 interval + -- and close both ends without any handshake I'd say in a way we are already simulating this case by writing the message and not waiting on receiving some sort of Ack. That's not right; resting a connection does not make it wait on an ack, the kernel will just forget the state of the connection when it sends the packet with RST option set. If the receiver does not get the packet it will get an error when next time it will try to send a packet (a reset will be send as a reply). — Reply to this email directly, view it on GitHub <#3532 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AE2SULO56E6NRHYQ53XDGLDUX6ZAHANCNFSM5JRGQCOQ> . You are receiving this because you authored the thread.Message ID: ***@***.***>

coot · 2022-01-28T09:15:34Z

ouroboros-network-framework/test/Test/Ouroboros/Network/Server2.hs

+    getTraceEvents :: forall a b. Typeable b
+                      => SimTrace a
+                      -> [(Time, b)]


if we write this function to return a Trace not a list of events, we will not need a separate splitConns (which is unfortunate, because this means we duplicate critical code for some of the tests).

There's traceSelectEventsDynamic which filters Dynamic values checking their type.
All together transitionSignal (a few lines above) is probably slightly more complex than:

transitionSignal :: [[(Time, AbstractTransitionTrace SimAddr)]] transitionSignal = Trace.toList . splitConns . traceSelectTraceEventsDynamic $ trace

The splitConns function that works on Trace does not get us the Time of the event which is needed for this particular test. That's why I duplicated the code. I gave your suggestion a go and it doesn't seem to have that type (it has [[AbstractTransition]] )

I think we lose the Time info when we go from SimTrace to Trace via traceSelectTraceEventsDynamic, that's why I duplicated the code to write a version that would give me the Time as well.

There's a fix for that by using contra-variance of the tracer. One needs to define

data WithTime a = WithTime Time a

And then use

tracerWithTime :: Tracer m (WithTime a) -> Tracer m a tracerWithTime (Tracer f) = Tracer $ \a -> WithTime <$> getMonotonicTime <*> f a

Interesting, but I am failing to see how that is going to help, multinodeExperiment requires Tracer m (WithName (Name peerAddr) (AbstractTransitionTrace peerAddr)). And we need to extract the time from SimEvent, at least it seems cleaner to extract it from there than from getMonotonicTime

What about adding

traceSelectTraceEventsTime :: (SimEventType -> Maybe b) -> SimTrace a -> Trace (SimResult a) (Time, b) traceSelectTraceEventsTime fn = bifoldr ( \ v _acc -> Nil v ) ( \ eventCtx acc -> case fn (seType eventCtx) of Nothing -> acc Just b -> Cons (seTime eventCtx, b) acc ) undefined -- it is ignored

to IOSim.hs ?

This would avoid making a convoluted change to this test's code and avoid duplication in this case, and I think it is a nice, justified addition to IOSim module

Note that here something similar is done.

I'd prefer to keep io-sim api as small as possible, the other place should also use contravariant tracer to get the time; another thing is that this also works in IO, not just io-sim.

I am afraid your suggestion does not typecheck :/ Tracer performs an m () action, so all we really can do is to perform getMonotonicTime in order to print it, not add it to WithTime

λ data WithTime a = WithTime Time a λ :t contramapM $ \a -> flip WithTime a <$> getMonotonicTime contramapM $ \a -> WithTime <$> getMonotonicTime <*> pure a :: MonadMonotonicTime m => Tracer m (WithTime a) -> Tracer m a

coot

LGTM, thanks @bolt12!

coot · 2022-02-03T10:23:15Z

network-mux/src/Network/Mux/Bearer/AttenuatedChannel.hs

+        Just q  ->
+          case msg of
+            MsgClose -> writeTVar qcWrite Nothing
+            _        -> writeTQueue q msg
+          >> return True


do notation is probably a better choice. >> nicely inlines with ->, I like $> too though some don't (e.g. Duncan).

This includes changes to the way a node behaves when its InboundGovernor dies: changed link to linkOnly (const True) to correctly propagate AsyncCancelled exceptions to the ConnectionManager and thus terminate it as well. The ConnectionManager needs to take care of closing the connection handlers of each connection in a way that does not make us go beyond the enforced timeouts. Since closing a connection is blocking we need to mask exceptions during the exception handler and since doing it sequentially can lead to waits on atomically blocks, we close each connection in parallel.

bolt12 · 2022-02-03T10:31:29Z

bors merge

3532: Added prop_timeouts_enforced r=bolt12 a=bolt12 Co-authored-by: Armando Santos <[email protected]>

This makes it so splitConns can be reused with any With type wrapper.

iohk-bors · 2022-02-03T11:08:41Z

Canceled.

bolt12 · 2022-02-03T11:09:00Z

bors merge

iohk-bors · 2022-02-03T11:22:06Z

Build succeeded:

ci/hydra:Cardano:ouroboros-network:required

3532: Added prop_timeouts_enforced r=bolt12 a=bolt12 Co-authored-by: Armando Santos <[email protected]>

bolt12 requested review from coot and karknu as code owners December 7, 2021 13:06

bolt12 force-pushed the bolt12/p2p-master-timeouts-enforced branch from 944f930 to f22bc05 Compare December 7, 2021 13:08

This was linked to issues Dec 7, 2021

Verify that connection-manager timeouts are enforced #3330

Closed

Verify that connection manager trace is valid #3465

Closed

coot requested changes Dec 16, 2021

View reviewed changes

bolt12 force-pushed the bolt12/p2p-master-timeouts-enforced branch from f22bc05 to 19823a8 Compare December 16, 2021 11:16

bolt12 requested a review from coot December 16, 2021 11:16

bolt12 force-pushed the bolt12/p2p-master-timeouts-enforced branch from 19823a8 to 1c6c416 Compare December 17, 2021 16:21

bolt12 mentioned this pull request Dec 20, 2021

ConnectionManager Timeouts not enforced within reasonable bounds #3553

Closed

bolt12 force-pushed the bolt12/p2p-master-timeouts-enforced branch from 1c6c416 to c959f27 Compare December 20, 2021 17:25

bolt12 force-pushed the bolt12/p2p-master-timeouts-enforced branch from c959f27 to 76b97be Compare January 10, 2022 17:46

bolt12 linked an issue Jan 11, 2022 that may be closed by this pull request

ConnectionManager Timeouts not enforced within reasonable bounds #3553

Closed

bolt12 force-pushed the bolt12/p2p-master-timeouts-enforced branch 4 times, most recently from be7358c to e0f47cd Compare January 12, 2022 14:21

bolt12 force-pushed the bolt12/p2p-master-timeouts-enforced branch from e0f47cd to b128aba Compare January 14, 2022 09:45

bolt12 changed the title ~~Added prop_connection_manager_timeouts_enforced~~ Added prop_timeouts_enforced Jan 14, 2022

bolt12 force-pushed the bolt12/p2p-master-timeouts-enforced branch from e0a6d71 to 3172691 Compare January 18, 2022 13:05

coot reviewed Jan 20, 2022

View reviewed changes

bolt12 force-pushed the bolt12/p2p-master-timeouts-enforced branch from 3172691 to 14a5304 Compare January 21, 2022 10:57

bolt12 requested a review from coot January 21, 2022 10:57

bolt12 force-pushed the bolt12/p2p-master-timeouts-enforced branch 2 times, most recently from 11a04f0 to 03c9390 Compare January 24, 2022 13:16

coot reviewed Jan 26, 2022

View reviewed changes

ouroboros-network-framework/src/Ouroboros/Network/ConnectionManager/Core.hs Show resolved Hide resolved

bolt12 force-pushed the bolt12/p2p-master-timeouts-enforced branch from 03c9390 to d44c87f Compare January 26, 2022 10:03

bolt12 requested a review from coot January 26, 2022 10:11

coot reviewed Jan 28, 2022

View reviewed changes

Added prop_connection_manager_timeouts_enforced

ced0507

bolt12 force-pushed the bolt12/p2p-master-timeouts-enforced branch from d44c87f to d5b7352 Compare January 28, 2022 11:00

bolt12 requested a review from coot February 1, 2022 17:42

bolt12 force-pushed the bolt12/p2p-master-timeouts-enforced branch from 3c58980 to bf01804 Compare February 2, 2022 14:14

coot approved these changes Feb 3, 2022

View reviewed changes

bolt12 added 3 commits February 3, 2022 10:30

Mimic SO_LINGER set with 0 interval channel close

c384550

Refactored inboundGovernorLoop error handling

c2919a9

bolt12 force-pushed the bolt12/p2p-master-timeouts-enforced branch from bf01804 to 10a5400 Compare February 3, 2022 10:30

iohk-bors bot added a commit that referenced this pull request Feb 3, 2022

Merge #3532

f47c30b

3532: Added prop_timeouts_enforced r=bolt12 a=bolt12 Co-authored-by: Armando Santos <[email protected]>

Refactor splitConns and multinodeExperiment

826f2db

This makes it so splitConns can be reused with any With type wrapper.

bolt12 force-pushed the bolt12/p2p-master-timeouts-enforced branch from 10a5400 to 826f2db Compare February 3, 2022 11:08

iohk-bors bot merged commit a3eafb5 into master Feb 3, 2022

iohk-bors bot deleted the bolt12/p2p-master-timeouts-enforced branch February 3, 2022 11:22

coot pushed a commit that referenced this pull request May 16, 2022

Merge #3532

25939f4

3532: Added prop_timeouts_enforced r=bolt12 a=bolt12 Co-authored-by: Armando Santos <[email protected]>

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Added prop_timeouts_enforced #3532

Added prop_timeouts_enforced #3532

bolt12 commented Dec 7, 2021 •

edited

Loading

bolt12 commented Jan 18, 2022 •

edited

Loading

coot Jan 20, 2022

bolt12 Jan 20, 2022

bolt12 Jan 21, 2022

coot Jan 26, 2022

bolt12 Jan 26, 2022

bolt12 Jan 26, 2022

coot Jan 20, 2022

bolt12 Jan 20, 2022

bolt12 Jan 21, 2022

coot Jan 24, 2022

bolt12 Jan 24, 2022

bolt12 commented Jan 26, 2022 via email

bolt12 commented Jan 26, 2022 via email

coot Jan 28, 2022

bolt12 Jan 28, 2022

bolt12 Jan 28, 2022

coot Jan 28, 2022 •

edited

Loading

bolt12 Jan 28, 2022

bolt12 Jan 28, 2022 •

edited

Loading

bolt12 Jan 28, 2022

coot Jan 28, 2022

bolt12 Feb 1, 2022

bolt12 Feb 1, 2022

coot left a comment

coot Feb 3, 2022 •

edited

Loading

bolt12 Feb 3, 2022

bolt12 commented Feb 3, 2022

iohk-bors bot commented Feb 3, 2022

bolt12 commented Feb 3, 2022

iohk-bors bot commented Feb 3, 2022

Added prop_timeouts_enforced #3532

Added prop_timeouts_enforced #3532

Conversation

bolt12 commented Dec 7, 2021 • edited Loading

bolt12 commented Jan 18, 2022 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

bolt12 commented Jan 26, 2022 via email

bolt12 commented Jan 26, 2022 via email

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

coot Jan 28, 2022 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

bolt12 Jan 28, 2022 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

coot left a comment

Choose a reason for hiding this comment

coot Feb 3, 2022 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

bolt12 commented Feb 3, 2022

iohk-bors bot commented Feb 3, 2022

bolt12 commented Feb 3, 2022

iohk-bors bot commented Feb 3, 2022

bolt12 commented Dec 7, 2021 •

edited

Loading

bolt12 commented Jan 18, 2022 •

edited

Loading

coot Jan 28, 2022 •

edited

Loading

bolt12 Jan 28, 2022 •

edited

Loading

coot Feb 3, 2022 •

edited

Loading