git.iko.soy/distributed-process
on master help sign in
Pass on registration trace events to clients
commitd251210eb3b76ad51fe394bb909903b3b242ce23 authorTim Watson <tim@rabbitmq.com> dateThu 28 Mar 2013, 17:23 (14 years ago) parent205fc8b
5 files changed+155−62
src/Control/Distributed/Process/Debug.hs+30−23 src/Control/Distributed/Process/Internal/Primitives.hs+1−1 src/Control/Distributed/Process/Internal/Trace/Tracer.hs+1−1 src/Control/Distributed/Process/Internal/Trace/Types.hs+20−16 tests/TestTracing.hs+103−21
src/Control/Distributed/Process/Debug.hs+30−23
@@ -42,9 +42,10 @@
4242-- trace handlers using Cloud Haskell's built-in delegation primitives.
4343--
4444-- The 'startTracer' function wraps the registered @tracer@ process with the
45−-- supplied handler, forwarding trace events to the original tracer. The
46−-- corresponding 'stopTracer' function terminates tracer processes in reverse
47−-- of the order in which they were started.
45+-- supplied handler and also forwarding trace events to the original tracer.
46+-- The corresponding 'stopTracer' function terminates tracer processes in
47+-- reverse of the order in which they were started, and re-establishes the
48+-- previous tracer process.
4849--
4950-- [Built in tracers]
5051--
@@ -53,32 +54,39 @@
5354-- can be configured using environment variables, or specified manually using
5455-- the 'traceEnable' function. The base tracer process cannot be
5556--
56−-- When a new local node is started, the contents of the environment variable
57−-- @DISTRIBUTED_PROCESS_TRACE_FILE@ are checked for a valid file path. If this
58−-- exists and the file can be opened for writing, all trace output will be
59−-- directed thence. If the environment variable is empty, the path invalid, or
60−-- the file is unavailable for writing - e.g., because another node has already
61−-- started tracing to it - then the @DISTRIBUTED_PROCESS_TRACE_CONSOLE@
62−-- environment variable is checked for /any/ non-empty value. If this is set,
63−-- then all trace output will be directed to the system logger process. If
64−-- neither variable provides a valid trace configuration, all internal traces
65−-- are written to "Debug.Trace.traceEventIO", which writes to the GHC eventlog.
57+-- When a new local node is started, the contents of several environment
58+-- variables are checked to determine how the default tracer process
59+-- will handle trace events. If none of these variables is set, then the
60+-- trace events will be effectively ignored, although they will still be
61+-- generated and passed through the system. Only one configuration will be
62+-- chosen - the first that contains a (valid) value. These environment
63+-- variables, in the order they're checked, are:
64+--
65+-- 1. @DISTRIBUTED_PROCESS_TRACE_FILE@
66+-- This is checked for a valid file path. If it exists and the file can be
67+-- opened for writing, all trace output will be directed thence. If the supplied
68+-- path is invalid, or the file is unavailable for writing - e.g., because
69+-- another node has already started tracing to it - then this tracer will be
70+-- disabled.
71+--
72+-- 2. @DISTRIBUTED_PROCESS_TRACE_CONSOLE@
73+-- This is checked for /any/ non-empty value. If set, then all trace output will
74+-- be directed to the system logger process.
75+--
76+-- 3. @DISTRIBUTED_PROCESS_TRACE_EVENTLOG@
77+-- This is checked for /any/ non-empty value. If set, all internal traces are
78+-- written to the GHC eventlog.
6679--
6780-- Users of the /simplelocalnet/ Cloud Haskell backend should also note that
6881-- because the trace file option only supports trace output from a single node
6982-- (so as to avoid interleaving), a file trace configured for the master node
70−-- will prevent slaves from tracing to the file and they will fall back to using
83+-- will prevent slaves from tracing to the file and will need to fall back to
7184-- the console or eventlog tracers instead.
7285--
73−-- Just as with the "Debug.Trace" module, this is a debugging/tracing facility
74−-- for use in development, and probably not best used in a production setting -
75−-- which is why the default behaviour is to trace to the GHC eventlog. For a
76−-- general purpose logging facility, you should consider 'say'.
77−--
7886-- Support for writing to the eventlog requires specific intervention to work,
79−-- without which traces are silently dropped/ignored and no output will be
80−-- generated. The GHC eventlog documentation provides information about enabling,
81−-- viewing and working with event traces at
87+-- without which, written traces are silently dropped/ignored and no output will
88+-- be generated. The GHC eventlog documentation provides information about
89+-- enabling, viewing and working with event traces at
8290-- <http://hackage.haskell.org/trac/ghc/wiki/EventLog>.
8391--
8492module Control.Distributed.Process.Debug
@@ -187,7 +195,6 @@ import Data.Binary()
187195import Prelude hiding (catch)
188196#endif
189197
190−
191198--------------------------------------------------------------------------------
192199-- Debugging/Tracing API --
193200--------------------------------------------------------------------------------
src/Control/Distributed/Process/Internal/Primitives.hs+1−1
@@ -888,7 +888,7 @@ say :: String -> Process ()
888888say string = do
889889 now <- liftIO getCurrentTime
890890 us <- getSelfPid
891− nsend "logger" (formatTime defaultTimeLocale "%c" now, us, string)
891+ nsend "logger" (formatTime defaultTimeLocale "[%d-%m-%Y] [%H:%M:%S-%q]" now, us, string)
892892
893893--------------------------------------------------------------------------------
894894-- Registry --
src/Control/Distributed/Process/Internal/Trace/Tracer.hs+1−1
@@ -271,7 +271,7 @@ handleTrace st msg ev@(TraceEvUnRegistered p n) =
271271 Just ns' -> Just (Set.delete n ns')
272272 regNames' = Map.alter f p (regNames st)
273273 in do
274− traceEv ev msg (traceRegistered (flags st)) st
274+ traceEv ev msg (traceUnregistered (flags st)) st
275275 return st { regNames = regNames' }
276276handleTrace st msg ev@(TraceEvSpawned _) = do
277277 traceEv ev msg (traceSpawned (flags st)) st >> return st
src/Control/Distributed/Process/Internal/Trace/Types.hs+20−16
@@ -89,25 +89,27 @@ data TraceSubject =
8989-- @Process@ events, take a 'TraceSubject' controlling which processes
9090-- should generate trace events in the target process.
9191data TraceFlags = TraceFlags {
92− traceSpawned :: !(Maybe TraceSubject) -- filter process spawned tracing
93− , traceDied :: !(Maybe TraceSubject) -- filter process died tracing
94− , traceRegistered :: !(Maybe TraceSubject) -- filter process registration tracing
95− , traceSend :: !(Maybe TraceSubject) -- filter process/message tracing by sender
96− , traceRecv :: !(Maybe TraceSubject) -- filter process/message tracing by receiver
97− , traceNodes :: !Bool -- enable node status trace events
98− , traceConnections :: !Bool -- enable connection status trace events
92+ traceSpawned :: !(Maybe TraceSubject) -- filter process spawned tracing
93+ , traceDied :: !(Maybe TraceSubject) -- filter process died tracing
94+ , traceRegistered :: !(Maybe TraceSubject) -- filter process registration tracing
95+ , traceUnregistered :: !(Maybe TraceSubject) -- filter process un-registration
96+ , traceSend :: !(Maybe TraceSubject) -- filter process/message tracing by sender
97+ , traceRecv :: !(Maybe TraceSubject) -- filter process/message tracing by receiver
98+ , traceNodes :: !Bool -- enable node status trace events
99+ , traceConnections :: !Bool -- enable connection status trace events
99100 } deriving (Typeable)
100101
101102defaultTraceFlags :: TraceFlags
102103defaultTraceFlags =
103104 TraceFlags {
104− traceSpawned = Nothing
105− , traceDied = Nothing
106− , traceRegistered = Nothing
107− , traceSend = Nothing
108− , traceRecv = Nothing
109− , traceNodes = False
110− , traceConnections = False
105+ traceSpawned = Nothing
106+ , traceDied = Nothing
107+ , traceRegistered = Nothing
108+ , traceUnregistered = Nothing
109+ , traceSend = Nothing
110+ , traceRecv = Nothing
111+ , traceNodes = False
112+ , traceConnections = False
111113 }
112114
113115data TraceArg =
@@ -180,8 +182,10 @@ instance Binary TraceSubject where
180182 _ -> error "TraceSubject.get - invalid header"
181183
182184instance Binary TraceFlags where
183− put (TraceFlags s d g m r n c) = put s >> put d >> put g >> put m >> put r >> put n >> put c
184− get = TraceFlags <$> get <*> get <*> get <*> get <*> get <*> get <*> get
185+ put (TraceFlags s d g u m r n c) =
186+ put s >> put d >> put g >> put u >> put m >> put r >> put n >> put c
187+ get =
188+ TraceFlags <$> get <*> get <*> get <*> get <*> get <*> get <*> get <*> get
185189
186190instance Binary TraceOk where
187191 put _ = return ()
tests/TestTracing.hs+103−21
@@ -77,7 +77,6 @@ testSpawnTracing result = do
7777 evSpawned <- liftIO $ newEmptyMVar
7878 evDied <- liftIO $ newEmptyMVar
7979 tracer <- startTracer $ \ev -> do
80− say "in spawn tracer..."
8180 case ev of
8281 (TraceEvSpawned p) -> liftIO $ putMVar evSpawned p
8382 (TraceEvDied p r) -> liftIO $ putMVar evDied (p, r)
@@ -96,9 +95,7 @@ testSpawnTracing result = do
9695 matchIf (\(ProcessMonitorNotification ref _ _) -> ref == mref)
9796 ((\_ -> return ()))
9897 ]
99− say "seen the death of tracer"
10098 setTraceFlags defaultTraceFlags
101− say "finishing setting default flags"
10299 stash result (tracedAlive == pid &&
103100 tracedDead == pid &&
104101 tracedReason == DiedNormal)
@@ -146,6 +143,79 @@ testTraceRecvNamedPid result = do
146143 stash result (res' && (p == pid))
147144 return ()
148145
146+testTraceSending :: TestResult Bool -> Process ()
147+testTraceSending result = do
148+ pid <- spawnLocal $ (expect :: Process String) >> return ()
149+ self <- getSelfPid
150+ res <- liftIO $ newEmptyMVar
151+ withFlags defaultTraceFlags { traceSend = traceOn } $ do
152+ withTracer
153+ (\ev ->
154+ case ev of
155+ (TraceEvSent to from _) ->
156+ stash res (to == pid && from == self)
157+ _ ->
158+ return ()) $ do
159+ send pid "hello there"
160+ res' <- liftIO $ takeMVar res
161+ stash result res'
162+
163+testTraceRegistration :: TestResult Bool -> Process ()
164+testTraceRegistration result = do
165+ (sp, rp) <- newChan
166+ pid <- spawnLocal $ do
167+ self <- getSelfPid
168+ () <- expect
169+ register "foobar" self
170+ sendChan sp ()
171+ () <- expect
172+ return ()
173+ res <- liftIO $ newEmptyMVar
174+ withFlags defaultTraceFlags { traceRegistered = traceOn } $ do
175+ withTracer
176+ (\ev ->
177+ case ev of
178+ TraceEvRegistered p s ->
179+ stash res (p == pid && s == "foobar")
180+ _ ->
181+ return ()) $ do
182+ _ <- monitor pid
183+ send pid ()
184+ () <- receiveChan rp
185+ send pid ()
186+ receiveWait [
187+ match (\(ProcessMonitorNotification _ _ _) -> return ())
188+ ]
189+ res' <- liftIO $ takeMVar res
190+ stash result res'
191+
192+testTraceUnRegistration :: TestResult Bool -> Process ()
193+testTraceUnRegistration result = do
194+ pid <- spawnLocal $ do
195+ () <- expect
196+ unregister "foobar"
197+ () <- expect
198+ return ()
199+ register "foobar" pid
200+ res <- liftIO $ newEmptyMVar
201+ withFlags defaultTraceFlags { traceUnregistered = traceOn } $ do
202+ withTracer
203+ (\ev ->
204+ case ev of
205+ TraceEvUnRegistered p n -> do
206+ stash res (p == pid && n == "foobar")
207+ send pid ()
208+ _ ->
209+ return ()) $ do
210+ mref <- monitor pid
211+ send pid ()
212+ receiveWait [
213+ matchIf (\(ProcessMonitorNotification mref' _ _) -> mref == mref')
214+ (\_ -> return ())
215+ ]
216+ res' <- liftIO $ takeMVar res
217+ stash result res'
218+
149219testTraceLayering :: TestResult () -> Process ()
150220testTraceLayering result = do
151221 pid <- spawnLocal $ do
@@ -154,8 +224,8 @@ testTraceLayering result = do
154224 traceMessage ("traceMsg", 123 :: Int)
155225 return ()
156226 withFlags defaultTraceFlags {
157− traceDied = traceOnly [pid]
158− , traceRecv = traceOnly ["foobar"]
227+ traceDied = traceOnly [pid]
228+ , traceRecv = traceOnly ["foobar"]
159229 } $ doTest pid result
160230 return ()
161231 where
@@ -171,22 +241,22 @@ testTraceLayering result = do
171241 ( do {
172242 recv <- liftIO $ newEmptyMVar
173243 ; withTracer
174− (\ev' ->
175− case ev' of
176− TraceEvReceived _ _ -> liftIO $ putMVar recv ()
177− _ -> return ())
178− ( do {
179− user <- liftIO $ newEmptyMVar
180− ; withTracer
181− (\ev'' ->
182− case ev'' of
183− TraceEvUser _ -> liftIO $ putMVar user ()
184− _ -> return ())
185− (send pid () >> (liftIO $ takeMVar user))
186− ; liftIO $ takeMVar recv
187− })
188− ; liftIO $ takeMVar died
189− })
244+ (\ev' ->
245+ case ev' of
246+ TraceEvReceived _ _ -> liftIO $ putMVar recv ()
247+ _ -> return ())
248+ ( do {
249+ user <- liftIO $ newEmptyMVar
250+ ; withTracer
251+ (\ev'' ->
252+ case ev'' of
253+ TraceEvUser _ -> liftIO $ putMVar user ()
254+ _ -> return ())
255+ (send pid () >> (liftIO $ takeMVar user))
256+ ; liftIO $ takeMVar recv
257+ })
258+ ; liftIO $ takeMVar died
259+ })
190260 liftIO $ putMVar result' ()
191261
192262tests :: LocalNode -> IO [Test]
@@ -212,6 +282,18 @@ tests node1 = do
212282 (delayedAssertion
213283 "expected a recv trace for the process registered as 'foobar'"
214284 node1 True testTraceRecvNamedPid lock)
285+ , testCase "Trace Send(er)"
286+ (delayedAssertion
287+ "expected a 'send' trace with the requisite fields set"
288+ node1 True testTraceSending lock)
289+ , testCase "Trace Registration"
290+ (delayedAssertion
291+ "expected a 'registered' trace"
292+ node1 True testTraceRegistration lock)
293+ , testCase "Trace Unregistration"
294+ (delayedAssertion
295+ "expected an 'unregistered' trace"
296+ node1 True testTraceUnRegistration lock)
215297 , testCase "Trace Layering"
216298 (delayedAssertion
217299 "expected blah"