Skip to content

Instantly share code, notes, and snippets.

@gonzalobf
Last active January 19, 2023 09:48
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save gonzalobf/9186724c72c47fc80e7d2265a6b8741f to your computer and use it in GitHub Desktop.
Save gonzalobf/9186724c72c47fc80e7d2265a6b8741f to your computer and use it in GitHub Desktop.
gen_udp:send benchmark
-module(gen_udp_benchmark).
% gen_udp:send benchmark
%
% This set of benchmarks runs gen_udp:send with a number of different values and
% configurations. It demonstrates that the time taken to run gen_udp:send changes
% depending on the number of messages the caller has in its queue.
%
% During each gen_udp execution:
% - no more messages are added to the caller's queue
% - the time taken to execute gen_udp:send remains constant when running in a
% loop. This confirms the first call takes as much as the rest of the calls
% (mean and median very similar).
%
% It can be observed that the execution time for gen_udp:send grows linearly with the number of messages in the queue, suggesting that
% gen_udp:send is scanning all the messages in the queue of the caller.
%
-behaviour(gen_server).
-export([
bench/0,
bench/3,
start/3,
send/2,
init/1,
handle_cast/2,
handle_call/3,
handle_info/2
]).
bench() ->
QueuedMessages = [100000, 1000000, 10000000],
OnOff = [on_heap, off_heap],
% Sends multiple messages in a loop and count how much each one takes
MessagesToSend = [1, 10, 100, 1000],
[
bench(QM, OO, MTS)
|| MTS <- MessagesToSend,
OO <- OnOff,
QM <- QueuedMessages
],
ok.
bench(QueuedMessages, OnOff, MessagesToSend) ->
{Pid, Ref} = spawn_monitor(
fun() ->
{ok, Pid} = start(QueuedMessages, OnOff, MessagesToSend),
send(Pid, QueuedMessages),
receive
done -> ok
end,
exit(Pid, kill)
end
),
% Wait to finish
receive
{'DOWN', Ref, process, Pid, normal} -> ok
end.
start(QueuedMessages, OnOff, MessagesToSend) ->
State = #{
messages => QueuedMessages, caller => self(), heap => OnOff, msg_to_send => MessagesToSend
},
gen_server:start(?MODULE, State, [{spawn_opt, [{message_queue_data, OnOff}]}]).
send(Pid, QueuedMessages) ->
gen_server:cast(Pid, send),
% Create a big binary to send it over and queue a lot of messages in the process queue
% Give the binary enough size so a ref is sent
BigBinary = <<<<"a">> || _ <- lists:seq(1, 10000)>>,
[Pid ! BigBinary || _ <- lists:seq(1, QueuedMessages)],
ok.
init(State) ->
erlang:process_flag(priority, high),
{ok, Socket} = gen_udp:open(
8780,
[
{active, true},
binary,
{sndbuf, 5000000}
]
),
{ok, State#{socket => Socket}}.
handle_cast(send, State) ->
#{
socket := Socket,
messages := Messages,
caller := Caller,
heap := OnOff,
msg_to_send := MsgToSend
} = State,
% Wait until we have all the expected messages in the queue, this won't change the messages in the queue
sleep_until_messages(Messages),
% Send a udp message and time it. There is a receive inside gen_udp:send that
% will need to iterate all queue looking for inet_reply
Times = [send_message(Socket) || _ <- lists:seq(1, MsgToSend)],
Min = lists:min(Times),
Max = lists:max(Times),
Mean = lists:sum(Times) / length(Times),
Median = median(Times),
Metrics = io_lib:format("~p (ms/message)", [
[{min, Min}, {max, Max}, {mean, Mean}, {median, Median}]
]),
io:format("~p msgs in queue, using ~p, sending ~p msg to gen_udp took -> ~s ~n", [
Messages, OnOff, MsgToSend, Metrics
]),
gen_udp:close(Socket),
Caller ! done,
{noreply, State}.
send_message(Socket) ->
Before = os:system_time(microsecond),
gen_udp:send(Socket, {127, 0, 0, 1}, 8789, <<"hey there!">>),
After = os:system_time(microsecond),
(After - Before) / 1000.
sleep_until_messages(Expected) ->
timer:sleep(1000),
{message_queue_len, Len} = erlang:process_info(self(), message_queue_len),
case Expected > Len of
true -> sleep_until_messages(Expected);
false -> ok
end.
median([]) ->
[];
median(L) ->
Sorted = lists:sort(L),
Length = length(L),
case Length rem 2 of
0 ->
[X, Y] = lists:sublist(Sorted, round(Length / 2), 2),
(X + Y) / 2;
1 ->
lists:nth(round((Length + 1) / 2), Sorted)
end.
handle_call(_, _, State) ->
{stop, ok, State}.
handle_info(_, State) ->
{noreply, State}.
@gonzalobf
Copy link
Author

$ erl                                                                                                                                                                         1216s 
Erlang/OTP 25 [erts-13.0] [source] [64-bit] [smp:12:12] [ds:12:12:10] [async-threads:1] [jit:ns]

Eshell V13.0  (abort with ^G)
1> c(gen_udp_benchmark).     
{ok,gen_udp_benchmark}
2> gen_udp_benchmark:bench().
100000 msgs in queue, using on_heap, sending 1 msg to gen_udp took -> [{min,0.723},{max,0.723},{mean,0.723},{median,0.723}] (ms/message) 
1000000 msgs in queue, using on_heap, sending 1 msg to gen_udp took -> [{min,6.947},{max,6.947},{mean,6.947},{median,6.947}] (ms/message) 
10000000 msgs in queue, using on_heap, sending 1 msg to gen_udp took -> [{min,64.104},{max,64.104},{mean,64.104},{median,64.104}] (ms/message) 

100000 msgs in queue, using off_heap, sending 1 msg to gen_udp took -> [{min,1.047},{max,1.047},{mean,1.047},{median,1.047}] (ms/message) 
1000000 msgs in queue, using off_heap, sending 1 msg to gen_udp took -> [{min,10.005},{max,10.005},{mean,10.005},{median,10.005}] (ms/message) 
10000000 msgs in queue, using off_heap, sending 1 msg to gen_udp took -> [{min,83.694},{max,83.694},{mean,83.694},{median,83.694}] (ms/message) 

100000 msgs in queue, using on_heap, sending 10 msg to gen_udp took -> [{min,0.619},{max,6.217},{mean,1.2789},{median,0.6385000000000001}] (ms/message) 
1000000 msgs in queue, using on_heap, sending 10 msg to gen_udp took -> [{min,6.269},{max,6.459},{mean,6.351699999999999},{median,6.346}] (ms/message) 
10000000 msgs in queue, using on_heap, sending 10 msg to gen_udp took -> [{min,69.59},{max,83.673},{mean,74.92480000000002},{median,73.1905}] (ms/message) 

100000 msgs in queue, using off_heap, sending 10 msg to gen_udp took -> [{min,0.888},{max,1.085},{mean,0.9968999999999999},{median,0.99}] (ms/message) 
1000000 msgs in queue, using off_heap, sending 10 msg to gen_udp took -> [{min,8.166},{max,10.102},{mean,8.838899999999999},{median,8.6475}] (ms/message) 
10000000 msgs in queue, using off_heap, sending 10 msg to gen_udp took -> [{min,87.878},{max,100.556},{mean,94.90979999999999}, {median,95.45949999999999}] (ms/message) 

100000 msgs in queue, using on_heap, sending 100 msg to gen_udp took -> [{min,0.539},{max,1.039},{mean,0.62459},{median,0.594}] (ms/message) 
1000000 msgs in queue, using on_heap, sending 100 msg to gen_udp took -> [{min,6.393},{max,11.826},{mean,6.820050000000001},{median,6.7445}] (ms/message) 
10000000 msgs in queue, using on_heap, sending 100 msg to gen_udp took -> [{min,65.964},{max,106.184},{mean,72.12127999999998},{median,70.334}] (ms/message) 

100000 msgs in queue, using off_heap, sending 100 msg to gen_udp took -> [{min,0.784},{max,1.31},{mean,0.93833},{median,0.927}] (ms/message) 
1000000 msgs in queue, using off_heap, sending 100 msg to gen_udp took -> [{min,8.213},{max,10.919},{mean,8.9017},{median,8.7605}] (ms/message) 
10000000 msgs in queue, using off_heap, sending 100 msg to gen_udp took -> [{min,82.526}, {max,106.824},{mean,86.26445000000001},{median,85.33699999999999}] (ms/message) 

100000 msgs in queue, using on_heap, sending 1000 msg to gen_udp took -> [{min,0.489},{max,1.561},{mean,0.6784709999999997},{median,0.583}] (ms/message) 
1000000 msgs in queue, using on_heap, sending 1000 msg to gen_udp took -> [{min,6.212},{max,13.978},{mean,6.648122999999992},{median,6.469}] (ms/message) 
10000000 msgs in queue, using on_heap, sending 1000 msg to gen_udp took -> [{min,62.808},{max,105.491},{mean,66.12047199999999}, {median,64.77850000000001}] (ms/message) 

100000 msgs in queue, using off_heap, sending 1000 msg to gen_udp took -> [{min,0.694},{max,1.536},{mean,0.8125630000000007},median,0.786}] (ms/message) 
1000000 msgs in queue, using off_heap, sending 1000 msg to gen_udp took -> [{min,7.994},{max,14.829},{mean,8.678199000000001},median,8.5435}] (ms/message) 
10000000 msgs in queue, using off_heap, sending 1000 msg to gen_udp took -> [{min,81.813},{max,115.004},{mean,86.79161600000019},median,85.9}] (ms/message) 


@gonzalobf
Copy link
Author

$ erl
Erlang/OTP 26 [DEVELOPMENT] [erts-13.1.2] [source-54e4353c70] [64-bit] [smp:12:12] [ds:12:12:10] [async-threads:1] [jit:ns]

Eshell V13.1.2 (press Ctrl+G to abort, type help(). for help)
(test@localhost)1> c(gen_udp_benchmark).     
{ok,gen_udp_benchmark}
(test@localhost)2> gen_udp_benchmark:bench().
100000 msgs in queue, using on_heap, sending 1 msg to gen_udp took -> [{min,3.036},{max,3.036},{mean,3.036},{median,3.036}] (ms/message) 
1000000 msgs in queue, using on_heap, sending 1 msg to gen_udp took -> [{min,25.833},{max,25.833},{mean,25.833},{median,25.833}] (ms/message) 
10000000 msgs in queue, using on_heap, sending 1 msg to gen_udp took -> [{min,71.192},{max,71.192},{mean,71.192},{median,71.192}] (ms/message) 

100000 msgs in queue, using off_heap, sending 1 msg to gen_udp took -> [{min,3.939},{max,3.939},{mean,3.939},{median,3.939}] (ms/message) 
1000000 msgs in queue, using off_heap, sending 1 msg to gen_udp took -> [{min,9.96},{max,9.96},{mean,9.96},{median,9.96}] (ms/message) 
10000000 msgs in queue, using off_heap, sending 1 msg to gen_udp took -> [{min,115.784},{max,115.784},{mean,115.784},{median,115.784}] (ms/message)

100000 msgs in queue, using on_heap, sending 10 msg to gen_udp took -> [{min,0.544},{max,0.715},{mean,0.6212},{median,0.615}] (ms/message) 
1000000 msgs in queue, using on_heap, sending 10 msg to gen_udp took -> [{min,6.542},{max,10.679},{mean,7.1206000000000005},{median,6.664}] (ms/message) 
10000000 msgs in queue, using on_heap, sending 10 msg to gen_udp took -> [{min,65.716},{max,71.273},{mean,68.4285},{median,68.54400000000001}] (ms/message)

100000 msgs in queue, using off_heap, sending 10 msg to gen_udp took -> [{min,0.641},{max,3.476},{mean,1.1517000000000002},{median,0.6915}] (ms/message) 
1000000 msgs in queue, using off_heap, sending 10 msg to gen_udp took -> [{min,8.268},{max,12.373},{mean,9.5066},{median,9.376999999999999}] (ms/message) 
10000000 msgs in queue, using off_heap, sending 10 msg to gen_udp took -> [{min,79.161},{max,92.004},{mean,81.7174},{median,80.54249999999999}] (ms/message)

100000 msgs in queue, using on_heap, sending 100 msg to gen_udp took -> [{min,0.495},{max,2.882},{mean,0.5640200000000002},{median,0.5125}] (ms/message) 
1000000 msgs in queue, using on_heap, sending 100 msg to gen_udp took -> [{min,6.279},{max,11.843},{mean,6.474399999999999},{median,6.3655}] (ms/message) 
10000000 msgs in queue, using on_heap, sending 100 msg to gen_udp took -> [{min,61.84},{max,110.104},{mean,65.83581},{median,63.8805}] (ms/message)

100000 msgs in queue, using off_heap, sending 100 msg to gen_udp took -> [{min,0.698},{max,1.027},{mean,0.7411999999999999},{median,0.726}] (ms/message) 
1000000 msgs in queue, using off_heap, sending 100 msg to gen_udp took -> [{min,7.706},{max,10.46},{mean,8.097730000000002},{median,7.958}] (ms/message) 
10000000 msgs in queue, using off_heap, sending 100 msg to gen_udp took -> [{min,78.26},{max,98.896},{mean,81.33081999999999},{median,80.7105}] (ms/message)

100000 msgs in queue, using on_heap, sending 1000 msg to gen_udp took -> [{min,0.454},{max,1.083},{mean,0.5378889999999994},{median,0.519}] (ms/message) 
1000000 msgs in queue, using on_heap, sending 1000 msg to gen_udp took -> [{min,6.266},{max,14.051},{mean,6.584880000000007},{median,6.432}] (ms/message) 
10000000 msgs in queue, using on_heap, sending 1000 msg to gen_udp took -> [{min,60.2},{max,125.801},{mean,67.29154700000001},{median,65.28049999999999}] (ms/message)

100000 msgs in queue, using off_heap, sending 1000 msg to gen_udp took -> [{min,0.619},{max,1.665},{mean,0.773132000000001},{median,0.718}] (ms/message) 
1000000 msgs in queue, using off_heap, sending 1000 msg to gen_udp took -> [{min,7.523},{max,15.006},{mean,8.117312000000002},{median,7.9765}] (ms/message) 
10000000 msgs in queue, using off_heap, sending 1000 msg to gen_udp took -> [{min,77.041},{max,166.736},{mean,81.44243300000002},{median,80.512}] (ms/message) 

@gonzalobf
Copy link
Author

Using socket as backend reduces the time execution for all cases

The change

$ diff -Zu gen_udp_benchmark_before.erl gen_udp_benchmark_after.erl                                                                                                                
--- gen_udp_benchmark_before.erl	2023-01-18 11:31:51.562175870 +0000
+++ gen_udp_benchmark_after.erl	2023-01-18 11:22:32.172536519 +0000
@@ -76,6 +76,7 @@
     {ok, Socket} = gen_udp:open(
         8780,
         [
+            {inet_backend, socket},
             {active, true},
             binary,
             {sndbuf, 5000000}

Before

3> gen_udp_benchmark:bench().
100000 msgs in queue, using on_heap, sending 1 msg to gen_udp took -> [{min,0.68},{max,0.68},{mean,0.68},{median,0.68}] (ms/message) 
1000000 msgs in queue, using on_heap, sending 1 msg to gen_udp took -> [{min,6.77},{max,6.77},{mean,6.77},{median,6.77}] (ms/message) 
10000000 msgs in queue, using on_heap, sending 1 msg to gen_udp took -> [{min,64.155},{max,64.155},{mean,64.155},{median,64.155}] (ms/message) 
100000 msgs in queue, using off_heap, sending 1 msg to gen_udp took -> [{min,1.254},{max,1.254},{mean,1.254},{median,1.254}] (ms/message) 
1000000 msgs in queue, using off_heap, sending 1 msg to gen_udp took -> [{min,21.33},{max,21.33},{mean,21.33},{median,21.33}] (ms/message) 
10000000 msgs in queue, using off_heap, sending 1 msg to gen_udp took -> [{min,105.585},{max,105.585},{mean,105.585},{median,105.585}] (ms/message) 
100000 msgs in queue, using on_heap, sending 10 msg to gen_udp took -> [{min,0.55},{max,4.342},{mean,0.9949000000000001},{median,0.6005}] (ms/message) 
1000000 msgs in queue, using on_heap, sending 10 msg to gen_udp took -> [{min,6.343},{max,6.647},{mean,6.468299999999999},{median,6.385}] (ms/message) 
10000000 msgs in queue, using on_heap, sending 10 msg to gen_udp took -> [{min,69.814},{max,73.371},{mean,71.4386},{median,71.8615}] (ms/message) 
100000 msgs in queue, using off_heap, sending 10 msg to gen_udp took -> [{min,2.062},{max,3.464},{mean,2.9379},{median,3.0324999999999998}] (ms/message) 
1000000 msgs in queue, using off_heap, sending 10 msg to gen_udp took -> [{min,8.0},{max,30.9},{mean,11.625800000000002},{median,8.126}] (ms/message) 
10000000 msgs in queue, using off_heap, sending 10 msg to gen_udp took -> [{min,83.205},{max,98.286},{mean,88.4812},{median,88.3395}] (ms/message) 
100000 msgs in queue, using on_heap, sending 100 msg to gen_udp took -> [{min,0.469},{max,1.186},{mean,0.5972199999999998},{median,0.537}] (ms/message) 
1000000 msgs in queue, using on_heap, sending 100 msg to gen_udp took -> [{min,6.207},{max,7.723},{mean,6.427929999999999},{median,6.324}] (ms/message) 
10000000 msgs in queue, using on_heap, sending 100 msg to gen_udp took -> [{min,60.8},{max,77.906},{mean,63.80821},{median,63.035}] (ms/message) 
100000 msgs in queue, using off_heap, sending 100 msg to gen_udp took -> [{min,0.64},{max,4.378},{mean,0.7381300000000003},{median,0.675}] (ms/message) 
1000000 msgs in queue, using off_heap, sending 100 msg to gen_udp took -> [{min,7.652},{max,12.113},{mean,8.01139},{median,7.9165}] (ms/message) 
10000000 msgs in queue, using off_heap, sending 100 msg to gen_udp took -> [{min,80.31},{max,117.104},{mean,87.09380999999999},{median,84.8035}] (ms/message) 
100000 msgs in queue, using on_heap, sending 1000 msg to gen_udp took -> [{min,0.481},{max,2.383},{mean,0.5610330000000008},{median,0.512}] (ms/message) 
1000000 msgs in queue, using on_heap, sending 1000 msg to gen_udp took -> [{min,6.173},{max,13.979},{mean,6.866885999999986},{median,6.419}] (ms/message) 
10000000 msgs in queue, using on_heap, sending 1000 msg to gen_udp took -> [{min,60.168},{max,128.717},{mean,65.39636599999999},{median,62.8755}] (ms/message) 
100000 msgs in queue, using off_heap, sending 1000 msg to gen_udp took -> [{min,0.624},{max,3.948},{mean,0.7897029999999989},{median,0.724}] (ms/message) 
1000000 msgs in queue, using off_heap, sending 1000 msg to gen_udp took -> [{min,7.683},{max,14.295},{mean,8.249641999999998},{median,8.03}] (ms/message) 
10000000 msgs in queue, using off_heap, sending 1000 msg to gen_udp took -> [{min,78.2},{max,122.686},{mean,82.55791900000001},{median,80.7195}] (ms/message) 

After

5> gen_udp_benchmark:bench().
100000 msgs in queue, using on_heap, sending 1 msg to gen_udp took -> [{min,0.051},{max,0.051},{mean,0.051},{median,0.051}] (ms/message) 
1000000 msgs in queue, using on_heap, sending 1 msg to gen_udp took -> [{min,0.038},{max,0.038},{mean,0.038},{median,0.038}] (ms/message) 
10000000 msgs in queue, using on_heap, sending 1 msg to gen_udp took -> [{min,0.038},{max,0.038},{mean,0.038},{median,0.038}] (ms/message) 
100000 msgs in queue, using off_heap, sending 1 msg to gen_udp took -> [{min,0.112},{max,0.112},{mean,0.112},{median,0.112}] (ms/message) 
1000000 msgs in queue, using off_heap, sending 1 msg to gen_udp took -> [{min,0.108},{max,0.108},{mean,0.108},{median,0.108}] (ms/message) 
10000000 msgs in queue, using off_heap, sending 1 msg to gen_udp took -> [{min,0.11},{max,0.11},{mean,0.11},{median,0.11}] (ms/message) 
100000 msgs in queue, using on_heap, sending 10 msg to gen_udp took -> [{min,0.006}, {max,0.041}, {mean,0.010000000000000004}, {median,0.006500000000000001}] (ms/message) 
1000000 msgs in queue, using on_heap, sending 10 msg to gen_udp took -> [{min,0.004},{max,0.038},{mean,0.0089},{median,0.005}] (ms/message) 
10000000 msgs in queue, using on_heap, sending 10 msg to gen_udp took -> [{min,0.025},{max,0.11},{mean,0.036800000000000006},{median,0.026}] (ms/message) 
100000 msgs in queue, using off_heap, sending 10 msg to gen_udp took -> [{min,0.025},{max,0.11},{mean,0.03690000000000001},{median,0.026}] (ms/message) 
1000000 msgs in queue, using off_heap, sending 10 msg to gen_udp took -> [{min,0.025},{max,0.105},{mean,0.03960000000000001},{median,0.026}] (ms/message) 
10000000 msgs in queue, using off_heap, sending 10 msg to gen_udp took -> [{min,0.025}, {max,0.107}, {mean,0.03870000000000001}, {median,0.025500000000000002}] (ms/message) 
100000 msgs in queue, using on_heap, sending 100 msg to gen_udp took -> [{min,0.004},{max,0.036},{mean,0.0051500000000000035},{median,0.005}] (ms/message) 
1000000 msgs in queue, using on_heap, sending 100 msg to gen_udp took -> [{min,0.004},{max,0.037},{mean,0.005420000000000004},{median,0.005}] (ms/message) 
10000000 msgs in queue, using on_heap, sending 100 msg to gen_udp took -> [{min,0.024},{max,0.137},{mean,0.03349999999999998},{median,0.026}] (ms/message) 
100000 msgs in queue, using off_heap, sending 100 msg to gen_udp took -> [{min,0.028},{max,0.106},{mean,0.03076999999999996},{median,0.029}] (ms/message) 
1000000 msgs in queue, using off_heap, sending 100 msg to gen_udp took -> [{min,0.024},{max,0.104},{mean,0.02879999999999997},{median,0.025}] (ms/message) 
10000000 msgs in queue, using off_heap, sending 100 msg to gen_udp took -> [{min,0.025},{max,0.101},{mean,0.02831999999999995},{median,0.025}] (ms/message) 
100000 msgs in queue, using on_heap, sending 1000 msg to gen_udp took -> [{min,0.004},{max,0.037},{mean,0.0048519999999999215},{median,0.005}] (ms/message) 
1000000 msgs in queue, using on_heap, sending 1000 msg to gen_udp took -> [{min,0.004},{max,0.036},{mean,0.004865999999999924},{median,0.005}] (ms/message) 
10000000 msgs in queue, using on_heap, sending 1000 msg to gen_udp took -> [{min,0.005},{max,0.036},{mean,0.005485999999999951},{median,0.005}] (ms/message) 
100000 msgs in queue, using off_heap, sending 1000 msg to gen_udp took -> [{min,0.016},{max,0.113},{mean,0.024591999999999673},{median,0.019}] (ms/message) 
1000000 msgs in queue, using off_heap, sending 1000 msg to gen_udp took -> [{min,0.008},{max,0.046},{mean,0.010234999999999873},{median,0.01}] (ms/message) 
10000000 msgs in queue, using off_heap, sending 1000 msg to gen_udp took -> [{min,0.012},{max,0.109},{mean,0.01815400000000026},{median,0.014}] (ms/message) 

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment