git.iko.soy/distributed-process
on master help sign in
Refactor Debug API and add a test suite
commit1520aa536a08847b496609e1e6ad23380301b27f authorTim Watson <tim@rabbitmq.com> dateSat 16 Mar 2013, 11:19 (14 years ago) parent08578e9
6 files changed+321−40
distributed-process.cabal+24 src/Control/Distributed/Process/Debug.hs+119−26 src/Control/Distributed/Process/Internal/Trace/Primitives.hs+26−4 src/Control/Distributed/Process/Internal/Trace/Tracer.hs+20−10 src/Control/Distributed/Process/Internal/Trace/Types.hs+9 tests/TestTracing.hs+123
distributed-process.cabal+24
@@ -157,6 +157,30 @@ Test-Suite TestStats
157157 ghc-options: -Wall -debug -eventlog -threaded -rtsopts -with-rtsopts=-N -fno-warn-unused-do-bind
158158 HS-Source-Dirs: tests
159159
160+Test-Suite TestTracing
161+ Type: exitcode-stdio-1.0
162+ Main-Is: TestTracing.hs
163+ Build-Depends: base >= 4.4 && < 5,
164+ random >= 1.0 && < 1.1,
165+ ansi-terminal >= 0.5 && < 0.6,
166+ containers >= 0.4 && < 0.6,
167+ stm >= 2.4 && < 2.5,
168+ distributed-process,
169+ network-transport >= 0.3 && < 0.4,
170+ network-transport-tcp >= 0.3 && < 0.4,
171+ binary >= 0.5 && < 0.7,
172+ network >= 2.3 && < 2.5,
173+ HUnit >= 1.2 && < 1.3,
174+ test-framework >= 0.6 && < 0.9,
175+ test-framework-hunit >= 0.2.0 && < 0.4,
176+ unix >= 2.5.0.0
177+ Extensions: CPP,
178+ ScopedTypeVariables,
179+ DeriveDataTypeable,
180+ GeneralizedNewtypeDeriving
181+ ghc-options: -Wall -debug -eventlog -threaded -rtsopts -with-rtsopts=-N -fno-warn-unused-do-bind
182+ HS-Source-Dirs: tests
183+
160184
161185Executable distributed-process-throughput
162186 if flag(benchmarks)
src/Control/Distributed/Process/Debug.hs+119−26
@@ -88,9 +88,14 @@ module Control.Distributed.Process.Debug
8888 , TraceFlags(..)
8989 , TraceSubject(..)
9090 -- * Configuring Tracing
91+ , isTracingEnabled
9192 , enableTrace
93+ , enableTraceAsync
9294 , disableTrace
95+ , disableTraceAsync
96+ , withTracer
9397 , setTraceFlags
98+ , setTraceFlagsAsync
9499 , defaultTraceFlags
95100 -- * Debugging
96101 , startTracer
@@ -113,9 +118,16 @@ import Control.Distributed.Process.Internal.Primitives
113118 , die
114119 , getSelfPid
115120 , reregister
116− , register
117121 , whereis
118122 , send
123+ , newChan
124+ , sendChan
125+ , receiveChan
126+ , receiveWait
127+ , matchIf
128+ , finally
129+ , try
130+ , monitor
119131 )
120132import Control.Distributed.Process.Internal.Types
121133 ( Tracer(..)
@@ -123,12 +135,15 @@ import Control.Distributed.Process.Internal.Types
123135 , ProcessId
124136 , Process
125137 , LocalProcess(..)
138+ , SendPort(..)
139+ , ProcessMonitorNotification(..)
126140 )
127141import Control.Distributed.Process.Internal.Trace.Types
128142 ( TraceArg(..)
129143 , TraceEvent(..)
130144 , TraceFlags(..)
131145 , TraceSubject(..)
146+ , TraceOk(..)
132147 , defaultTraceFlags
133148 )
134149import Control.Distributed.Process.Internal.Trace.Tracer
@@ -141,17 +156,27 @@ import qualified Control.Distributed.Process.Internal.Trace.Primitives as Tracer
141156 , traceLogFmt
142157 , traceMessage
143158 , enableTrace
159+ , enableTraceSync
144160 , disableTrace
161+ , disableTraceSync
145162 , setTraceFlags
163+ , setTraceFlagsSync
146164 )
147165import Control.Distributed.Process.Node
148166import Control.Distributed.Process.Serializable
149167
168+import Control.Exception (SomeException)
169+
150170import Control.Monad.IO.Class (liftIO)
151171import Control.Monad.Reader (ask)
152172
153173import Data.Binary()
154174
175+#if ! MIN_VERSION_base(4,6,0)
176+import Prelude hiding (catch)
177+#endif
178+
179+
155180--------------------------------------------------------------------------------
156181-- Debugging/Tracing API --
157182--------------------------------------------------------------------------------
@@ -161,24 +186,56 @@ import Data.Binary()
161186-- the registered tracer with the supplied handler, allowing the user to layer
162187-- multiple tracers on top of one another, with trace events forwarded down
163188-- through all the layers in turn. Once the top layer is stopped, it will
164−-- reregister the original tracer pid before terminating. If no tracer is
165−-- currently registered, this function will have no effect.
166−startTracer :: (TraceEvent -> Process ()) -> Process ()
167−startTracer handler = withRegisteredTracer $ \pid -> do
168− node <- processNode <$> ask
169− newPid <- liftIO $ forkProcess node $ do
170− finally (mkProxy pid handler)
171− (reregister "tracer" pid)
172− enableTrace newPid
189+-- reregister the original (prior) tracer pid before terminating.
190+startTracer :: (TraceEvent -> Process ()) -> Process ProcessId
191+startTracer handler = do
192+ (sp, rp) <- newChan
193+ withRegisteredTracer $ \pid -> do
194+ node <- processNode <$> ask
195+ newPid <- liftIO $ forkProcess node $ do
196+ -- TODO: we ensure that the original
197+ -- tracer is re-registered, but it is
198+ -- possible this could lead to races
199+ -- if multiple tracers crash in very
200+ -- close succession, due to scheduling
201+ finally (traceProxy pid handler)
202+ (resetTracer pid)
203+ enableTrace newPid
204+ sendChan sp newPid
205+ receiveChan rp
206+
207+-- | Evaluate @proc@ with tracing enabled via @handler@, and immediately
208+-- disable tracing thereafter, before giving the result (or exception
209+-- in case of failure).
210+withTracer :: forall a.
211+ (TraceEvent -> Process ())
212+ -> Process a
213+ -> Process (Either SomeException a)
214+withTracer handler proc = do
215+ tracer <- startTracer handler
216+ finally (try proc)
217+ (stopTracing tracer)
173218 where
174− mkProxy :: ProcessId -> (TraceEvent -> Process ()) -> Process ()
175− mkProxy pid act = do
176− getSelfPid >>= register "tracer"
177− proxy pid $ \(ev :: TraceEvent) ->
178− case ev of
179− (TraceEvTakeover _) -> die "finished"
180− TraceEvDisable -> die "stop"
181− _ -> act ev >> return True
219+ stopTracing :: ProcessId -> Process ()
220+ stopTracing tracer = do
221+ ref <- monitor tracer
222+ stopTracer
223+ receiveWait [
224+ matchIf (\(ProcessMonitorNotification ref' _ _) -> ref == ref')
225+ (\_ -> return ())
226+ ]
227+
228+traceProxy :: ProcessId -> (TraceEvent -> Process ()) -> Process ()
229+traceProxy pid act = do
230+ getSelfPid >>= reregister "tracer" -- registration is synchronous
231+ proxy pid $ \(ev :: TraceEvent) ->
232+ case ev of
233+ (TraceEvTakeover _) -> die "takeover"
234+ TraceEvDisable -> die "disabled"
235+ _ -> act ev >> return True
236+
237+resetTracer :: ProcessId -> Process ()
238+resetTracer pid = enableTrace pid
182239
183240-- | Stops a user supplied tracer started with 'startTracer'.
184241-- Note that only one tracer process can be active at any given time.
@@ -190,7 +247,7 @@ startTracer handler = withRegisteredTracer $ \pid -> do
190247-- This function will never stop the system tracer (i.e., the tracer
191248-- initially started when the node is created), therefore once all user
192249-- supplied tracers (i.e., processes started via 'startTracer') have exited,
193−-- subsequent calls to this function have no effect.
250+-- subsequent calls to this function will have no effect.
194251--
195252-- If tracing is support disabled for the node, this function will also
196253-- have no effect.
@@ -209,22 +266,57 @@ stopTracer = withLocalTracer $ \t ->
209266
210267withRegisteredTracer :: (ProcessId -> Process ()) -> Process ()
211268withRegisteredTracer act = do
212− t <- whereis "tracer"
213− case t of
214− Nothing -> return ()
215− Just pid -> act pid
269+ currentTracer <- whereis "tracer"
270+ case currentTracer of
271+ Nothing -> do { (Just p') <- whereis "tracer.initial"; act p' }
272+ (Just p) -> act p
273+
274+-- | Determine whether or not tracing has been enabled.
275+isTracingEnabled :: Process Bool
276+isTracingEnabled = do
277+ node <- processNode <$> ask
278+ case (localTracer node) of
279+ (ActiveTracer _ _) -> return True
280+ _ -> return False
216281
217282-- | Enable tracing to the supplied process.
283+enableTraceAsync :: ProcessId -> Process ()
284+enableTraceAsync pid = withLocalTracer $ \t -> liftIO $ Tracer.enableTrace t pid
285+
286+-- TODO: refactor _Sync versions of trace configuration functions...
287+
288+-- | Enable tracing to the supplied process and wait for a @TraceOk@
289+-- response from the trace coordinator process.
218290enableTrace :: ProcessId -> Process ()
219−enableTrace pid = withLocalTracer $ \t -> liftIO $ Tracer.enableTrace t pid
291+enableTrace pid =
292+ withLocalTracerSync $ \t sp -> Tracer.enableTraceSync t sp pid
220293
221294-- | Disable the currently configured trace.
295+disableTraceAsync :: Process ()
296+disableTraceAsync = withLocalTracer $ \t -> liftIO $ Tracer.disableTrace t
297+
298+-- | Disable the currently configured trace and wait for a @TraceOk@
299+-- response from the trace coordinator process.
222300disableTrace :: Process ()
223−disableTrace = withLocalTracer $ \t -> liftIO $ Tracer.disableTrace t
301+disableTrace =
302+ withLocalTracerSync $ \t sp -> Tracer.disableTraceSync t sp
224303
225304-- | Set the given flags for the current tracer.
305+setTraceFlagsAsync :: TraceFlags -> Process ()
306+setTraceFlagsAsync f = withLocalTracer $ \t -> liftIO $ Tracer.setTraceFlags t f
307+
308+-- | Set the given flags for the current tracer and wait for a @TraceOk@
309+-- response from the trace coordinator process.
226310setTraceFlags :: TraceFlags -> Process ()
227−setTraceFlags f = withLocalTracer $ \t -> liftIO $ Tracer.setTraceFlags t f
311+setTraceFlags f =
312+ withLocalTracerSync $ \t sp -> Tracer.setTraceFlagsSync t sp f
313+
314+withLocalTracerSync :: (Tracer -> SendPort TraceOk -> IO ()) -> Process ()
315+withLocalTracerSync act = do
316+ (sp, rp) <- newChan
317+ withLocalTracer $ \t -> liftIO $ (act t sp)
318+ TraceOk <- receiveChan rp
319+ return ()
228320
229321-- | Send a log message to the internal tracing facility. If tracing is
230322-- enabled, this will create a custom trace log event.
@@ -246,3 +338,4 @@ withLocalTracer :: (Tracer -> Process ()) -> Process ()
246338withLocalTracer act = do
247339 node <- processNode <$> ask
248340 act (localTracer node)
341+
src/Control/Distributed/Process/Internal/Trace/Primitives.hs+26−4
@@ -12,8 +12,11 @@ module Control.Distributed.Process.Internal.Trace.Primitives
1212 -- * Configuring A Tracer
1313 , defaultTraceFlags
1414 , enableTrace
15+ , enableTraceSync
1516 , disableTrace
17+ , disableTraceSync
1618 , setTraceFlags
19+ , setTraceFlagsSync
1720 ) where
1821
1922import Control.Distributed.Process.Internal.CQueue (enqueue)
@@ -22,12 +25,14 @@ import Control.Distributed.Process.Internal.Trace.Types
2225 , TraceEvent(..)
2326 , SetTrace(..)
2427 , TraceFlags(..)
28+ , TraceOk(..)
2529 , defaultTraceFlags
2630 )
2731import Control.Distributed.Process.Internal.Types
2832 ( Tracer(..)
2933 , ProcessId
3034 , Message
35+ , SendPort
3136 , createUnencodedMessage
3237 )
3338import Control.Distributed.Process.Serializable
@@ -59,17 +64,34 @@ traceMessage :: Serializable m => Tracer -> m -> IO ()
5964traceMessage tr msg = traceEvent tr (TraceEvUser (createUnencodedMessage msg))
6065
6166enableTrace :: Tracer -> ProcessId -> IO ()
62−enableTrace t p = traceIt t (createUnencodedMessage (TraceEnable p))
67+enableTrace t p =
68+ traceIt t (createUnencodedMessage ((Nothing :: Maybe (SendPort TraceOk)),
69+ (TraceEnable p)))
70+
71+enableTraceSync :: Tracer -> SendPort TraceOk -> ProcessId -> IO ()
72+enableTraceSync t s p =
73+ traceIt t (createUnencodedMessage ((Just s), (TraceEnable p)))
6374
6475disableTrace :: Tracer -> IO ()
65−disableTrace t = traceIt t (createUnencodedMessage TraceDisable)
76+disableTrace t =
77+ traceIt t (createUnencodedMessage ((Nothing :: Maybe (SendPort TraceOk)),
78+ TraceDisable))
79+
80+disableTraceSync :: Tracer -> SendPort TraceOk -> IO ()
81+disableTraceSync t s =
82+ traceIt t (createUnencodedMessage ((Just s), TraceDisable))
6683
6784setTraceFlags :: Tracer -> TraceFlags -> IO ()
68−setTraceFlags t f = traceIt t (createUnencodedMessage f)
85+setTraceFlags t f =
86+ traceIt t (createUnencodedMessage ((Nothing :: Maybe (SendPort TraceOk)), f))
87+
88+setTraceFlagsSync :: Tracer -> SendPort TraceOk -> TraceFlags -> IO ()
89+setTraceFlagsSync t s f =
90+ traceIt t (createUnencodedMessage ((Just s), f))
6991
7092traceIt :: Tracer -> Message -> IO ()
7193traceIt InactiveTracer _ = return ()
7294traceIt (ActiveTracer _ wqRef) msg = do
7395 mQueue <- deRefWeak wqRef
7496 forM_ mQueue $ \queue -> enqueue queue msg
75−
97+
src/Control/Distributed/Process/Internal/Trace/Tracer.hs+20−10
@@ -22,10 +22,12 @@ import Control.Distributed.Process.Internal.Primitives
2222 ( catch
2323 , receiveWait
2424 , forward
25+ , sendChan
2526 , match
2627 , matchAny
2728 , matchAnyIf
2829 , handleMessage
30+ , reregister
2931 )
3032import Control.Distributed.Process.Internal.Trace.Types
3133 ( TraceEvent(..)
@@ -33,6 +35,7 @@ import Control.Distributed.Process.Internal.Trace.Types
3335 , Addressable(..)
3436 , TraceSubject(..)
3537 , TraceFlags(..)
38+ , TraceOk(..)
3639 , defaultTraceFlags
3740 )
3841import Control.Distributed.Process.Internal.Types
@@ -44,6 +47,7 @@ import Control.Distributed.Process.Internal.Types
4447 , Identifier(..)
4548 , ProcessSignal(NamedSend)
4649 , Message
50+ , SendPort
4751 , forever'
4852 , nullProcessId
4953 , createUnencodedMessage
@@ -125,7 +129,6 @@ systemLoggerTracer = do
125129
126130eventLogTracer :: Process ()
127131eventLogTracer = do
128− liftIO $ traceEventIO "starting event log tracer"
129132 -- NB: when the GHC event log supports tracing arbitrary (ish) data, we will
130133 -- almost certainly use *that* facility independently of whether or not there
131134 -- is a tracer process installed. This is just a stop gap until then.
@@ -177,22 +180,29 @@ traceController mv = do
177180 -- events to the ghc eventlog, at which point this design might change.
178181 st' <- receiveWait [
179182 -- we notify the previous tracer process that it has been replaced
180− match (\(set :: SetTrace) ->
183+ match (\(setResp, set :: SetTrace) -> do
181184 -- We allow at most one trace target, which is a process id.
182185 case set of
183186 (TraceEnable pid) -> do
184187 sendTrace st (createUnencodedMessage (TraceEvTakeover pid))
188+ reregister "tracer" pid
189+ sendOk setResp
185190 return st { sendTrace = (mkSender pid) }
186191 TraceDisable -> do
187192 sendTrace st (createUnencodedMessage TraceEvDisable)
188− return st { sendTrace = (\_ -> return ()) })
189− , match (\flags' -> applyTraceFlags flags' st)
190− -- we dequeue incoming messages even if we don't process them
193+ sendOk setResp >> return st { sendTrace = (\_ -> return ()) })
194+ , match (\(confResp, flags') ->
195+ sendOk confResp >> applyTraceFlags flags' st) -- setTraceFlags
196+ -- we dequeue incoming events even if we don't process them
191197 , matchAny (\ev ->
192− handleMessage ev (handleTrace st ev) >>= return . fromMaybe st)
198+ handleMessage ev (handleTrace st ev) >>= return . fromMaybe st)
193199 ]
194200 traceLoop st'
195201
202+ sendOk :: Maybe (SendPort TraceOk) -> Process ()
203+ sendOk Nothing = return ()
204+ sendOk (Just sp) = sendChan sp TraceOk
205+
196206 mkSender :: ProcessId -> (Message -> Process ())
197207 mkSender pid = (flip forward) pid
198208
@@ -236,9 +246,9 @@ handleTrace st _ (TraceEvUnRegistered p n) =
236246 Just ns' -> Just (Set.delete n ns')
237247 regNames' = Map.alter f p (regNames st)
238248 in return st { regNames = regNames' }
239−handleTrace st msg ev@(TraceEvSpawned _) =
249+handleTrace st msg ev@(TraceEvSpawned _) = do
240250 traceEv ev msg (traceSpawned (flags st)) st >> return st
241−handleTrace st msg ev@(TraceEvDied _ _) =
251+handleTrace st msg ev@(TraceEvDied _ _) = do
242252 traceEv ev msg (traceDied (flags st)) st >> return st
243253handleTrace st msg ev@(TraceEvSent _ _ _) =
244254 traceEv ev msg (traceSend (flags st)) st >> return st
@@ -263,8 +273,8 @@ traceEv :: TraceEvent
263273 -> Maybe TraceSubject
264274 -> TracerState
265275 -> Process ()
266−traceEv _ _ Nothing _ = return ()
267−traceEv _ msg (Just TraceAll) st = (sendTrace st) msg
276+traceEv _ _ Nothing _ = return ()
277+traceEv _ msg (Just TraceAll) st = (sendTrace st) msg
268278traceEv ev msg (Just (TraceProcs pids)) st = do
269279 node <- processNode <$> ask
270280 let p = case resolveToPid ev of
src/Control/Distributed/Process/Internal/Trace/Types.hs+9
@@ -8,6 +8,7 @@ module Control.Distributed.Process.Internal.Trace.Types
88 , TraceFlags(..)
99 , defaultTraceFlags
1010 , TraceArg(..)
11+ , TraceOk(..)
1112 ) where
1213
1314import Control.Applicative ((<$>), (<*>))
@@ -111,6 +112,10 @@ data TraceArg =
111112 TraceStr String
112113 | forall a. (Show a) => Trace a
113114
115+-- | A generic 'ok' response from the trace coordinator.
116+data TraceOk = TraceOk
117+ deriving (Typeable)
118+
114119--------------------------------------------------------------------------------
115120-- Binary Instances --
116121--------------------------------------------------------------------------------
@@ -176,3 +181,7 @@ instance Binary TraceFlags where
176181 put (TraceFlags s d m r n c) = put s >> put d >> put m >> put r >> put n >> put c
177182 get = TraceFlags <$> get <*> get <*> get <*> get <*> get <*> get
178183
184+instance Binary TraceOk where
185+ put _ = return ()
186+ get = return TraceOk
187+
tests/TestTracing.hsnew file+123
@@ -0,0 +1,123 @@
1+{-# LANGUAGE DeriveDataTypeable #-}
2+{-# OPTIONS_GHC -fno-warn-orphans #-}
3+module Main where
4+
5+import Control.Concurrent.MVar
6+ ( MVar
7+ , newEmptyMVar
8+ , putMVar
9+ , takeMVar
10+ )
11+import Control.Distributed.Process
12+import Control.Distributed.Process.Debug
13+import Control.Distributed.Process.Node
14+ ( forkProcess
15+ , newLocalNode
16+ , initRemoteTable
17+ , closeLocalNode
18+ , LocalNode)
19+import Control.Exception as Ex (catch)
20+import Data.Binary()
21+import Data.Typeable()
22+import Network.Transport.TCP
23+import Prelude hiding (catch, log)
24+import Test.Framework
25+ ( Test
26+ , defaultMain
27+ , testGroup
28+ )
29+import Test.HUnit (Assertion)
30+import Test.HUnit.Base (assertBool)
31+import Test.Framework.Providers.HUnit (testCase)
32+
33+import System.Environment (getEnv)
34+import System.Posix.Env
35+ ( setEnv
36+ )
37+
38+-- these utilities have been cribbed from distributed-process-platform
39+-- we should really find a way to share them...
40+
41+-- | A mutable cell containing a test result.
42+type TestResult a = MVar a
43+
44+delayedAssertion :: (Eq a) => String -> LocalNode -> a ->
45+ (TestResult a -> Process ()) -> Assertion
46+delayedAssertion note localNode expected testProc = do
47+ result <- newEmptyMVar
48+ _ <- forkProcess localNode $ testProc result
49+ assertComplete note result expected
50+
51+assertComplete :: (Eq a) => String -> MVar a -> a -> IO ()
52+assertComplete msg mv a = do
53+ b <- takeMVar mv
54+ assertBool msg (a == b)
55+
56+stash :: TestResult a -> a -> Process ()
57+stash mvar x = liftIO $ putMVar mvar x
58+
59+------
60+
61+testSpawnTracing :: TestResult Bool -> Process ()
62+testSpawnTracing result = do
63+ setTraceFlags defaultTraceFlags {
64+ traceSpawned = (Just TraceAll)
65+ , traceDied = (Just TraceAll)
66+ }
67+
68+ evSpawned <- liftIO $ newEmptyMVar
69+ evDied <- liftIO $ newEmptyMVar
70+ startTracer $ \ev -> do
71+ case ev of
72+ (TraceEvSpawned p) -> liftIO $ putMVar evSpawned p
73+ (TraceEvDied p r) -> liftIO $ putMVar evDied (p, r)
74+ _ -> return ()
75+
76+ (sp, rp) <- newChan
77+ pid <- spawnLocal $ do
78+ sendChan sp ()
79+ () <- receiveChan rp
80+
81+ tracedAlive <- liftIO $ takeMVar evSpawned
82+ (tracedDead, tracedReason) <- liftIO $ takeMVar evDied
83+
84+ stopTracer
85+ stash result (tracedAlive == pid &&
86+ tracedDead == pid &&
87+ tracedReason == DiedNormal)
88+
89+tests :: LocalNode -> IO [Test]
90+tests node1 = do
91+ enabled <- checkTraceEnabled
92+ case enabled of
93+ True ->
94+ return [
95+ testGroup "Process Info" [
96+ testCase "Test Spawn Tracing"
97+ (delayedAssertion
98+ "expected dead process-info to be ProcessInfoNone"
99+ node1 True testSpawnTracing)
100+ ] ]
101+ False ->
102+ return []
103+
104+checkTraceEnabled :: IO Bool
105+checkTraceEnabled =
106+ Ex.catch (getEnv "DISTRIBUTED_PROCESS_TRACE_ENABLED" >> return True)
107+ (\(_ :: IOError) -> return False)
108+
109+
110+mkNode :: String -> IO LocalNode
111+mkNode port = do
112+ Right (transport1, _) <- createTransportExposeInternals
113+ "127.0.0.1" port defaultTCPParameters
114+ newLocalNode transport1 initRemoteTable
115+
116+main :: IO ()
117+main = do
118+ setEnv "DISTRIBUTED_PROCESS_TRACE_ENABLED" "true" True
119+ node1 <- mkNode "8081"
120+ testData <- tests node1
121+ defaultMain testData
122+ closeLocalNode node1
123+ return ()