?

Log in

No account? Create an account

Previous Entry | Next Entry

Message passing ring benchmark in erlang

Last week we saw it took about 100microseconds to make a process.

This week we see that Erlang takes only 1 microsecond to send a message between processes.

solutions to chapter 8 of Programming Erlang by Joe Armstrong under the cut

http://www.pragprog.com/titles/jaerlang/programming-erlang



5> c(proc_ring).                          
{ok,proc_ring}
6> proc_ring:runlist({10000,1000},{10,1}).
Procs 1, Messages 1 per message time 0.0 uS (0.0 uS)
Procs 1, Messages 2 per message time 0.0 uS (0.0 uS)
Procs 1, Messages 3 per message time 0.0 uS (0.0 uS)
Procs 1, Messages 4 per message time 0.0 uS (0.0 uS)
Procs 1, Messages 5 per message time 0.0 uS (0.0 uS)
Procs 1, Messages 6 per message time 0.0 uS (0.0 uS)
Procs 1, Messages 7 per message time 0.0 uS (0.0 uS)
Procs 1, Messages 8 per message time 0.0 uS (0.0 uS)
Procs 1, Messages 9 per message time 0.0 uS (0.0 uS)
Procs 1, Messages 10 per message time 0.0 uS (0.0 uS)
Procs 1001, Messages 1 per message time 0.0 uS (0.999000999000999 uS)
Procs 1001, Messages 2 per message time 0.0 uS (0.999000999000999 uS)
Procs 1001, Messages 3 per message time 0.0 uS (0.999000999000999 uS)
Procs 1001, Messages 4 per message time 2.4975024975024973 uS (0.999000999000999 uS)
Procs 1001, Messages 5 per message time 0.0 uS (0.999000999000999 uS)
Procs 1001, Messages 6 per message time 0.0 uS (0.8325008325008325 uS)
Procs 1001, Messages 7 per message time 1.4271442842871414 uS (0.8562865705722849 uS)
Procs 1001, Messages 8 per message time 1.2487512487512487 uS (0.7492507492507493 uS)
Procs 1001, Messages 9 per message time 1.11000111000111 uS (0.666000666000666 uS)
Procs 1001, Messages 10 per message time 0.999000999000999 uS (0.7992007992007992 uS)
Procs 2001, Messages 1 per message time 0.0 uS (0.9995002498750625 uS)
Procs 2001, Messages 2 per message time 0.0 uS (1.249375312343828 uS)
Procs 2001, Messages 3 per message time 0.0 uS (0.8329168748958854 uS)
Procs 2001, Messages 4 per message time 1.249375312343828 uS (0.9995002498750625 uS)
Procs 2001, Messages 5 per message time 0.9995002498750625 uS (0.8995502248875562 uS)
Procs 2001, Messages 6 per message time 0.8329168748958854 uS (0.9162085623854739 uS)
Procs 2001, Messages 7 per message time 0.7139287499107589 uS (0.9995002498750625 uS)
Procs 2001, Messages 8 per message time 1.249375312343828 uS (0.9370314842578711 uS)
Procs 2001, Messages 9 per message time 1.1105558331945138 uS (0.9439724582153368 uS)
Procs 2001, Messages 10 per message time 0.9995002498750625 uS (0.8495752123938031 uS)
Procs 3001, Messages 1 per message time 3.332222592469177 uS (0.9996667777407531 uS)
Procs 3001, Messages 2 per message time 1.6661112962345885 uS (0.9996667777407531 uS)
Procs 3001, Messages 3 per message time 1.1107408641563923 uS (0.9996667777407531 uS)
Procs 3001, Messages 4 per message time 1.6661112962345885 uS (1.0829723425524824 uS)
Procs 3001, Messages 5 per message time 1.3328890369876707 uS (1.0663112295901367 uS)
Procs 3001, Messages 6 per message time 1.1107408641563923 uS (1.1107408641563923 uS)
Procs 3001, Messages 7 per message time 0.9520635978483363 uS (1.0472699576331699 uS)
Procs 3001, Messages 8 per message time 1.2495834721759413 uS (1.0829723425524824 uS)
Procs 3001, Messages 9 per message time 1.1107408641563923 uS (1.0737161686845125 uS)
Procs 3001, Messages 10 per message time 0.9996667777407531 uS (1.0996334555148284 uS)
Procs 4001, Messages 1 per message time 2.4993751562109474 uS (0.9997500624843789 uS)
Procs 4001, Messages 2 per message time 0.0 uS (1.1247188202949263 uS)
Procs 4001, Messages 3 per message time 0.8331250520703157 uS (1.0830625676914105 uS)
Procs 4001, Messages 4 per message time 0.6248437890527369 uS (1.1247188202949263 uS)
Procs 4001, Messages 5 per message time 0.9997500624843789 uS (1.0497375656085979 uS)
Procs 4001, Messages 6 per message time 0.8331250520703157 uS (0.9997500624843789 uS)
Procs 4001, Messages 7 per message time 1.071160781233263 uS (0.9997500624843789 uS)
Procs 4001, Messages 8 per message time 0.9372656835791052 uS (1.0622344413896525 uS)
Procs 4001, Messages 9 per message time 1.110833402760421 uS (1.0830625676914105 uS)
Procs 4001, Messages 10 per message time 0.9997500624843789 uS (1.0497375656085979 uS)
Procs 5001, Messages 1 per message time 1.9996000799840032 uS (0.9998000399920016 uS)
Procs 5001, Messages 2 per message time 0.9998000399920016 uS (0.9998000399920016 uS)
Procs 5001, Messages 3 per message time 0.6665333599946678 uS (1.0664533759914683 uS)
Procs 5001, Messages 4 per message time 0.9998000399920016 uS (1.0497900419916018 uS)
Procs 5001, Messages 5 per message time 1.1997600479904018 uS (1.1597680463907218 uS)
Procs 5001, Messages 6 per message time 0.9998000399920016 uS (0.9998000399920016 uS)
Procs 5001, Messages 7 per message time 0.8569714628502871 uS (1.0283657554203445 uS)
Procs 5001, Messages 8 per message time 0.9998000399920016 uS (0.9998000399920016 uS)
Procs 5001, Messages 9 per message time 1.1108889333244463 uS (1.0442355973249795 uS)
Procs 5001, Messages 10 per message time 0.9998000399920016 uS (1.0197960407918416 uS)
Procs 6001, Messages 1 per message time 1.6663889351774703 uS (0.9998333611064822 uS)
Procs 6001, Messages 2 per message time 1.6663889351774703 uS (1.0831528078653558 uS)
Procs 6001, Messages 3 per message time 1.1109259567849803 uS (1.0553796589457312 uS)
Procs 6001, Messages 4 per message time 1.2497917013831028 uS (1.0831528078653558 uS)
Procs 6001, Messages 5 per message time 0.9998333611064822 uS (1.066488918513581 uS)
Procs 6001, Messages 6 per message time 0.8331944675887352 uS (1.0553796589457312 uS)
Procs 6001, Messages 7 per message time 1.1902778108410503 uS (1.0712500297569452 uS)
Procs 6001, Messages 8 per message time 1.041493084485919 uS (1.0623229461756374 uS)
Procs 6001, Messages 9 per message time 1.1109259567849803 uS (1.0183487937195652 uS)
Procs 6001, Messages 10 per message time 0.9998333611064822 uS (1.066488918513581 uS)
Procs 7001, Messages 1 per message time 1.4283673760891302 uS (0.999857163262391 uS)
Procs 7001, Messages 2 per message time 0.7141836880445651 uS (1.0712755320668477 uS)
Procs 7001, Messages 3 per message time 0.9522449173927534 uS (1.0950816550016664 uS)
Procs 7001, Messages 4 per message time 0.7141836880445651 uS (1.0712755320668477 uS)
Procs 7001, Messages 5 per message time 0.857020425653478 uS (1.0569918583059563 uS)
Procs 7001, Messages 6 per message time 0.9522449173927534 uS (1.02366328619721 uS)
Procs 7001, Messages 7 per message time 1.224314893790683 uS (1.0610729079519252 uS)
Procs 7001, Messages 8 per message time 1.0712755320668477 uS (0.999857163262391 uS)
Procs 7001, Messages 9 per message time 1.110952403624879 uS (1.0792109063784538 uS)
Procs 7001, Messages 10 per message time 0.999857163262391 uS (1.0284245107841736 uS)
Procs 8001, Messages 1 per message time 0.0 uS (0.9998750156230471 uS)
Procs 8001, Messages 2 per message time 0.6249218847644045 uS (0.9998750156230471 uS)
Procs 8001, Messages 3 per message time 0.8332291796858726 uS (0.9998750156230471 uS)
Procs 8001, Messages 4 per message time 0.9373828271466067 uS (1.0623672040994876 uS)
Procs 8001, Messages 5 per message time 0.9998750156230471 uS (1.0498687664041995 uS)
Procs 8001, Messages 6 per message time 1.249843769528809 uS (1.0623672040994876 uS)
Procs 8001, Messages 7 per message time 1.071294659596122 uS (1.0891495705893905 uS)
Procs 8001, Messages 8 per message time 1.0936132983377078 uS (1.0779902512185977 uS)
Procs 8001, Messages 9 per message time 1.1109722395811634 uS (1.0415364746073408 uS)
Procs 8001, Messages 10 per message time 0.9998750156230471 uS (1.0248718910136232 uS)
Procs 9001, Messages 1 per message time 1.1109876680368849 uS (1.1109876680368849 uS)
Procs 9001, Messages 2 per message time 0.5554938340184424 uS (0.9998889012331963 uS)
Procs 9001, Messages 3 per message time 0.7406584453579232 uS (0.9998889012331963 uS)
Procs 9001, Messages 4 per message time 1.1109876680368849 uS (1.0832129763359626 uS)
Procs 9001, Messages 5 per message time 0.8887901344295078 uS (1.0665481613154093 uS)
Procs 9001, Messages 6 per message time 0.925823056697404 uS (1.0554382846350405 uS)
Procs 9001, Messages 7 per message time 0.9522751440316155 uS (1.047502658434777 uS)
Procs 9001, Messages 8 per message time 1.1109876680368849 uS (1.0415509387845794 uS)
Procs 9001, Messages 9 per message time 0.9875445938105643 uS (0.9998889012331963 uS)
Procs 9001, Messages 10 per message time 0.9998889012331963 uS (1.0443284079546717 uS)
[ok,ok,ok,ok,ok,ok,ok,ok,ok,ok,ok,ok,ok,ok,ok,ok,ok,ok,ok,
 ok,ok,ok,ok,ok,ok,ok,ok,ok,ok|...]


And my totally unoptimized solution:


-module(proc_ring).
-export([
runlist/2,
run/1,
start/2,
clock/1,
loop/1,
tail_loop/3,
for/3,
head/1
]).

%% spawn a head process, register it.
%% spawn Procs-1 body processes in an array.
%% link each process in the array to the
%% process.
%% link the last one to the head.
%% link the head to the first process

%% send the message around from the head.
%% clock it each time it passes the head.




runlist({MaxProc,Pstep},{MaxMsg,Mstep})->
[run([A,B])||A<-lists:seq(1,MaxProc,Pstep),
B<-lists:seq(1,MaxMsg,Mstep)];
runlist(MaxProc,MaxMsg)->
[run([A,B])||A<-lists:seq(1,MaxProc),
B<-lists:seq(1,MaxMsg)].

run([Procs,Messages])->
io:format("Procs ~p, Messages ~p ",[Procs,Messages]),
L = start(Procs,Messages),
H = head(L),
{U1,U2} = clock(H),
Tmsg = Procs*Messages,
T1 = U1/Tmsg,
T2 = U2/Tmsg,
io:format("per message time ~p uS (~p uS)~n",[T1,T2]).

start(Procs,Messages)->
Tail = spawn(proc_ring,tail_loop,[1,Messages,fun()->a end]),
List = [Tail|spawnlist(2,Procs, Tail)],
Rev = lists:reverse(List),
[Head|_]=Rev,
sender(Tail,{update,Head}),
List.

head(Proclist)->
[H|_]=lists:reverse(Proclist),
H.

clock(Pid)->
% io:format("starting ring benchmark~n"),
statistics(runtime),
statistics(wall_clock),
Pid!{self(),transmit},
receive
{done}->
{_,Time1}=statistics(runtime),
{_,Time2}=statistics(wall_clock),
Pid!{die},
U1 = Time1 * 1000,
U2 = Time2 * 1000
%io:format("CPU ~p uS, wall ~p uS~n",
% [U1,U2])
end,
{U1,U2}.



spawnlist(I,N,PrevPid) when I>=N->
[init(PrevPid)];
spawnlist(I,N,PrevPid) ->
ThisPid = init(PrevPid),
[ThisPid|spawnlist(I+1,N,ThisPid)].



for(I,N,Fun) when I > N->
[Fun()];
for(I,N,Fun) ->
[Fun()|for(I+1,N,Fun)].

init(Pid)->
Me = spawn(proc_ring,loop,[Pid]),
% io:format("I, ~p, have the target ~p~n",[Me,Pid]),
Me.

sender(Pid,Request)->
Pid ! Request.


loop(Pid)->
receive
{From,transmit}->
% io:format("Process ~p transmitting~n",[self()]),
sender(Pid,{From,transmit}),
loop(Pid);
{update,Pid2} ->
% io:format("Process ~p has new target ~p~n",[self(),Pid2]),
loop(Pid2);
{report} ->
io:format("Process ~p has target ~p~n",[self(),Pid]),
sender(Pid,{report}),
loop(Pid);
{die} ->
sender(Pid,die),
void
end.

tail_loop(I,Messages,Pid)->
receive
{From,transmit}->
case I < Messages of
true ->
% io:format("Tail Process ~p transmitting ~n",[self()]),
sender(Pid,{From,transmit}),
tail_loop(I+1,Messages,Pid);
false->
From!{done},
tail_loop(I,Messages,Pid)
end;
{update,Pid2} ->
% io:format("Tail Process ~p has new target ~p~n",[self(),Pid2]),
tail_loop(I,Messages,Pid2);
{report} ->
io:format("Tail process ~p has target ~p~n",[self(),Pid]),
tail_loop(I,Messages,Pid);
{die} ->
sender(Pid,die),
void
end.





Oddly enough, message time stayed constant at about 1uS even at very high loads.

Procs 80001, Messages 8 per message time 1.0156123048461894 uS (1.0140498243771954 uS)
Procs 80001, Messages 9 per message time 1.013876215436196 uS (1.02082057307617 uS)
Procs 80001, Messages 10 per message time 1.0124873439082012 uS (1.0187372657841778 uS)
Procs 90001, Messages 1 per message time 0.9999888890123443 uS (1.0444328396351152 uS)
Procs 90001, Messages 2

Tasks: 164 total, 1 running, 163 sleeping, 0 stopped, 0 zombie
Cpu0 : 1.3%us, 4.0%sy, 0.0%ni, 62.0%id, 32.7%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu1 : 1.9%us, 2.3%sy, 0.0%ni, 82.8%id, 13.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu2 : 2.0%us, 11.8%sy, 0.0%ni, 62.1%id, 23.9%wa, 0.0%hi, 0.3%si, 0.0%st
Cpu3 : 1.3%us, 13.4%sy, 0.0%ni, 70.1%id, 15.3%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 4009608k total, 3991276k used, 18332k free, 368k buffers
Swap: 6062072k total, 6059412k used, 2660k free, 66864k cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ P COMMAND
47 sysroot 15 -5 0 0 0 D 20.6 0.0 0:16.23 2 kswapd0
6581 me 20 0 9991m 3.6g 860 S 17.6 93.8 0:46.58 2 beam.smp
6255 me 20 0 14856 712 436 R 0.3 0.0 0:06.28 1 top




before the computer totally locked up when 100% of RAM and swap were consumed at about 90001 processes each sending 1 message to their next process in the ring for two complete rotations.