Cleaned up manual tracing code in word_split and ebb_worker.

src/ebb_worker.erl

@@ -3,6 +3,7 @@
 -export([start_link/3, start_link/4, stop/1]).
 
 -export([worker/3, worker/5]).
+-export([worker_traced/3, worker_traced/5]).
 
 start_link(Func, Args, Receiver) ->
     try
@@ -32,14 +33,23 @@ worker(Func, Args, Receiver) ->
     ebb_event:return(Receiver, apply(Func, Args)).
 
 worker(Root, Node, Func, Args, Receiver) ->
+    ebb_event:return(Receiver, apply(Func, Args)),
+    ebb_work_manager:work_finished(Root, Node).
+
+trace(Node, Worker, Args) ->
     Ref = make_ref(),
-    io:format("~p ~p: Worker thread started~n", [Node, Ref]),
+    io:format("~p<< ~p worker thread start~n", [Node, Ref]),
     {_, _, Start} = erlang:now(),
-    ebb_event:return(Receiver, apply(Func, Args)),
+    apply(Worker, Args),
     {_, _, Finish} = erlang:now(),
-    io:format("~p ~p: Worker thread finished, time ~p~n",
-	      [Node, Ref, Finish-Start]),
-    ebb_work_manager:work_finished(Root, Node).
+    io:format("~p>> ~p worker thread finish (~p usec)~n",
+	      [Node, Ref, Finish-Start]).
+
+worker_traced(Func, Args, Receiver) ->
+    trace(node(), fun worker/3, [Func, Args, Receiver]).
+
+worker_traced(Root, Node, Func, Args, Receiver) ->
+    trace(Node, fun worker/5, [Root, Node, Func, Args, Receiver]).
 
 stop(Worker) ->
     exit(Worker, kill).

src/word_split.erl

@@ -1,5 +1,6 @@
 -module(word_split).
 -export([words/1, to_list/1, words_from_file/1]).
+-export([words_traced/1]).
 
 % data WordState = {chunk, S} | {segment, L, C, R}
 
@@ -25,26 +26,13 @@ maybe_word(S) ->
     singleton(S).
 
 process_char(C) ->
-    io:format("~p: process_char start~n", [node()]),
-    {_, _, Start} = erlang:now(),
-    Result = case lists:member(C, " \t\n\f") of
-		 true ->
-		     {segment, "", nil(), ""};
-		 false ->
-		     {chunk, [C]}
-	     end,
-    {_, _, Finish} = erlang:now(),
-    io:format("~p: process_char finish, time ~p~n", [node(), Finish-Start]),
-    Result.
+    case lists:member(C, " \t\n\f") of
+	true ->
+	    {segment, "", nil(), ""};
+	false ->
+	    {chunk, [C]}
+    end.
 
-combine_timed(Arg1, Arg2) ->
-    io:format("~p: combine start~n", [node()]),
-    {_, _, Start} = erlang:now(),
-    Result = combine(Arg1, Arg2),
-    {_, _, Finish} = erlang:now(),
-    io:format("~p: combine finish, time ~p~n", [node(), Finish-Start]),
-    Result.
-    
 combine({chunk, S1}, {chunk, S2}) ->
     {chunk, S1 ++ S2};
 combine({chunk, S}, {segment, L, C, R}) ->
@@ -54,9 +42,29 @@ combine({segment, L, C, R}, {chunk, S}) ->
 combine({segment, L1, C1, R1}, {segment, L2, C2, R2}) ->
     {segment, L1, conc(C1, conc(maybe_word(R1 ++ L2), C2)), R2}.
 
+trace(Name, Time, Units, Func, Args) ->
+    io:format("~p<< ~s start~n", [node(), Name]),
+    Start = Time(),
+    Result = apply(Func, Args),
+    Finish = Time(),
+    io:format("~p>> ~s finish (~s ~p)~n", [node(), Name, Units, Finish-Start]),
+    Result.
+
+trace_usec(Name, Func, Args) ->
+    trace(Name, fun() -> element(3, erlang:now()) end, "usec", Func, Args).
+
+trace_sec(Name, Func, Args) ->
+    trace(Name, fun() -> element(2, erlang:now()) end, "sec", Func, Args).
+
+process_char_traced(C) ->
+    trace_usec("word_split:process_char/1", fun process_char/1, [C]).
+
+combine_traced(Piece1, Piece2) ->
+    trace_usec("word_split:combine/2", fun combine/2, [Piece1, Piece2]).
+
 words(Str) ->
     T = ebb_flow:map_reduce(fun(X) -> process_char(X) end,
-			    fun(X, Y) -> combine_timed(X, Y) end,
+			    fun(X, Y) -> combine(X, Y) end,
 			    Str),
     case ebb_run:run_distributed(T) of
 	{ok, [{chunk, S}]} ->
@@ -67,11 +75,14 @@ words(Str) ->
 	    error
     end.
 
+words_traced(Str) ->
+    trace_sec("words", fun words/1, [Str]).
+
 words_from_file(Str) ->
     case file:read_file(Str) of
 	{ok, Data} ->
-	    io:format("Number of words: ~w\n", [length(words(binary_to_list(Data)))]);
+	    io:format("Number of words: ~w\n",
+		      [length(words(binary_to_list(Data)))]);
 	_ ->
 	    io:format("File not found!")
     end.
-