From 84adefa331c4159d432d22840663c38f155cd4c1 Mon Sep 17 00:00:00 2001 From: Erlang/OTP Date: Fri, 20 Nov 2009 14:54:40 +0000 Subject: The R13B03 release. --- lib/megaco/examples/meas/megaco_codec_meas.erl | 655 +++++++++++++++++++++++++ 1 file changed, 655 insertions(+) create mode 100644 lib/megaco/examples/meas/megaco_codec_meas.erl (limited to 'lib/megaco/examples/meas/megaco_codec_meas.erl') diff --git a/lib/megaco/examples/meas/megaco_codec_meas.erl b/lib/megaco/examples/meas/megaco_codec_meas.erl new file mode 100644 index 0000000000..88b34105ac --- /dev/null +++ b/lib/megaco/examples/meas/megaco_codec_meas.erl @@ -0,0 +1,655 @@ +%% +%% %CopyrightBegin% +%% +%% Copyright Ericsson AB 2002-2009. All Rights Reserved. +%% +%% The contents of this file are subject to the Erlang Public License, +%% Version 1.1, (the "License"); you may not use this file except in +%% compliance with the License. You should have received a copy of the +%% Erlang Public License along with this software. If not, it can be +%% retrieved online at http://www.erlang.org/. +%% +%% Software distributed under the License is distributed on an "AS IS" +%% basis, WITHOUT WARRANTY OF ANY KIND, either express or implied. See +%% the License for the specific language governing rights and limitations +%% under the License. +%% +%% %CopyrightEnd% +%% + +%% +%%---------------------------------------------------------------------- +%% Purpose: Measure megaco codec's encoding & decoding time's +%% +%% Measurement process consists of: +%% For each message in a directory: +%% Pre: Read message from the file, close the file +%% Measurement: 1) measure decode +%% 2) measure encode (of the previously decoded message) +%% Post: Print average +%% For each directory: +%% A summery is written, both to the console and to a file, +%% in an excel compatible format. +%% +%% megaco_codec_meas:t(). +%% megaco_codec_meas:t([pretty, compact]). +%% megaco_codec_meas:t([per, pretty, compact]). +%% +%%---------------------------------------------------------------------- + +-module(megaco_codec_meas). + +%% -compile(export_all). + + +%% API +-export([start/0, start/1]). +-export([start1/0]). + +%% Internal exports +-export([do_measure_codec/7, do_measure_codec_loop/7]). +-export([flex_scanner_handler/1]). + + +-include_lib("kernel/include/file.hrl"). + +-define(V3, v3). + +-define(MEASURE_TIMEOUT, 100000). % 100 sec + +-ifndef(MEASURE_COUNT_TIME). +-define(MEASURE_COUNT_TIME, 1*1000*1000). % 1 seconds +-endif. + +-ifndef(MEASURE_TIME). +-define(MEASURE_TIME, 10000). +-endif. + +-ifndef(MEASURE_CODECS). +-define(MEASURE_CODECS, megaco_codec_transform:codecs()). +-endif. + +-define(DEFAULT_MESSAGE_PACKAGE, megaco_codec_transform:default_message_package()). + +-record(stat, {name, ecount, etime, dcount, dtime, size}). + + +%% Runs the measurement on all "official" codecs + +start1() -> + put(everbose,true), + start(). + +start() -> + meas_init(?DEFAULT_MESSAGE_PACKAGE, ?MEASURE_CODECS). + +start([MessagePackage]) -> + do_start(MessagePackage, ?MEASURE_CODECS); +start(MessagePackage) -> + do_start(MessagePackage, ?MEASURE_CODECS). + +do_start(MessagePackageRaw, Codecs) -> + MessagePackage = parse_message_package(MessagePackageRaw), + meas_init(MessagePackage, Codecs). + +parse_message_package(MessagePackageRaw) when is_list(MessagePackageRaw) -> + list_to_atom(MessagePackageRaw); +parse_message_package(MessagePackage) when is_atom(MessagePackage) -> + MessagePackage; +parse_message_package(BadMessagePackage) -> + throw({error, {bad_message_package, BadMessagePackage}}). + + +%% Dirs is a list of directories containing files, +%% each with a single megaco message. +%% +%% Note that it is a requirement that each dir has +%% the name of the codec with which the messages has +%% been encoded: +%% +%% pretty | compact | ber | per | erlang +%% + +meas_init(MessagePackage, Codecs) -> + %% process_flag(trap_exit, true), + io:format("~nRun meas on message package: ~p~n~n", [MessagePackage]), + display_os_info(), + display_system_info(), + display_app_info(), + io:format("~n", []), + Started = now(), + case megaco_codec_transform:messages(MessagePackage) of + Messages when is_list(Messages) -> + ExpandedMessages = expand_messages(Codecs, Messages), + Results = t1(ExpandedMessages, []), + display_time(Started, now()), + store_results(Results); + Error -> + Error + end. + +display_os_info() -> + V = case os:version() of + {Major, Minor, Release} -> + lists:flatten( + io_lib:format("~w.~w.~w", [Major, Minor, Release])); + Str -> + Str + end, + case os:type() of + {OsFam, OsName} -> + io:format("OS: ~p-~p: ~s~n", [OsFam, OsName, V]); + OsFam -> + io:format("OS: ~p: ~s~n", [OsFam, V]) + end. + +display_system_info() -> + SysArch = string:strip(erlang:system_info(system_architecture),right,$\n), + SysVer = string:strip(erlang:system_info(system_version),right,$\n), + io:format("System architecture: ~s~n", [SysArch]), + io:format("System version: ~s~n", [SysVer]), + ok. + + +display_app_info() -> + display_megaco_info(), + display_asn1_info(). + +display_megaco_info() -> + MI = megaco:module_info(), + {value, {attributes, Attr}} = lists:keysearch(attributes, 1, MI), + {value, {app_vsn, Ver}} = lists:keysearch(app_vsn, 1, Attr), + FlexStr = + case megaco_flex_scanner:is_enabled() of + true -> + case megaco_flex_scanner:is_reentrant_enabled() of + true -> + "reentrant flex"; + false -> + "non-reentrant flex" + end; + false -> + "no flex" + end, + io:format("Megaco version: ~s (~s)~n", [Ver, FlexStr]). + +display_asn1_info() -> + AI = megaco_ber_bin_drv_media_gateway_control_v1:info(), + Vsn = + case lists:keysearch(vsn, 1, AI) of + {value, {vsn, V}} when is_atom(V) -> + atom_to_list(V); + {value, {vsn, V}} when is_list(V) -> + V; + _ -> + "unknown" + end, + io:format("ASN.1 version: ~s~n", [Vsn]). + + +%% {MegaSec, Sec, MicroSec} +display_time(Start, Fin) -> + FormatDate1 = format_timestamp(Start), + FormatDate2 = format_timestamp(Fin), + FormatDiff = format_diff(Start, Fin), + io:format("Started: ~s~n", [FormatDate1]), + io:format("Finished: ~s~n", [FormatDate2]), + io:format(" ~s~n~n~n", [FormatDiff]), + ok. + +format_timestamp({_N1, _N2, N3} = Now) -> + {Date, Time} = calendar:now_to_datetime(Now), + {YYYY,MM,DD} = Date, + {Hour,Min,Sec} = Time, + FormatDate = + io_lib:format("~.4w:~.2.0w:~.2.0w ~.2.0w:~.2.0w:~.2.0w 4~w", + [YYYY,MM,DD,Hour,Min,Sec,round(N3/1000)]), + lists:flatten(FormatDate). + +format_diff(Start, Fin) -> + DateTime1 = calendar:now_to_universal_time(Start), + DateTime2 = calendar:now_to_universal_time(Fin), + T1 = calendar:datetime_to_gregorian_seconds(DateTime1), + T2 = calendar:datetime_to_gregorian_seconds(DateTime2), + {_, Diff} = calendar:gregorian_seconds_to_datetime(T2 - T1), + Tmp = + case Diff of + {0, 0, S} -> + io_lib:format("~.2.0w sec", [S]); + {0, M, S} -> + io_lib:format("~w min ~.2.0w sec", [M,S]); + {H, M, S} -> + io_lib:format("~w hour ~w min ~.2.0w sec", [H,M,S]) + end, + lists:flatten(Tmp). + + + +t1([], Results) -> + lists:reverse(Results); +t1([{Id, Codec, Conf, _, _} = ECodec|EMsgs], Results) -> + case (catch measure(ECodec)) of + {'EXIT', Reason} -> + error("measure of codec ~p exited: ~n~p", [Codec, Reason]), + t1(EMsgs, Results); + {error, Reason} -> + error("skipping codec ~p: ~n~p", [Codec, Reason]), + t1(EMsgs, Results); + {ok, Res} -> + t1(EMsgs, [{Id, Conf, Res}| Results]) + end. + + +measure({Id, Codec, Conf, Count, Msgs}) -> + io:format("measure using codec ~p ~p~n ", [Codec, Conf]), + {Init, Conf1} = measure_init(Conf), + Conf2 = [{version3,?V3}|Conf1], + Res = measure(Id, Codec, Conf2, Msgs, [], Count), + measure_fin(Init), + Res. + + +expand_messages(Codecs, Messages) -> + ECodecs = expand_codecs(Codecs, []), + expand_messages(ECodecs, Messages, []). + +expand_messages([], _, EMessages) -> + lists:reverse(EMessages); +expand_messages([{Id, Codec, Conf, Count} | ECodecs], Messages, EMessages) -> + case lists:keysearch(Id, 1, Messages) of + {value, {Id, Msgs}} -> + expand_messages(ECodecs, Messages, + [{Id, Codec, Conf, Count, Msgs}|EMessages]); + false -> + exit({error, {no_such_codec_data, Id}}) + end. + +expand_codecs([], ECodecs) -> + lists:reverse(lists:flatten(ECodecs)); +expand_codecs([Codec|Codecs], ECodecs) when is_atom(Codec) -> + ECodec = expand_codec(Codec), + expand_codecs(Codecs, [ECodec|ECodecs]). + +expand_codec(Codec) -> + case Codec of + pretty -> + [{Codec, megaco_pretty_text_encoder, [flex_scanner], 2000}, + {Codec, megaco_pretty_text_encoder, [], 1000}]; + compact -> + [{Codec, megaco_compact_text_encoder, [flex_scanner], 3000}, + {Codec, megaco_compact_text_encoder, [], 1500}]; + ber -> + [{Codec, megaco_ber_bin_encoder, [driver,native], 4000}, + {Codec, megaco_ber_bin_encoder, [native], 3000}, + {Codec, megaco_ber_bin_encoder, [driver], 3000}, + {Codec, megaco_ber_bin_encoder, [], 1000}]; + per -> + [{Codec, megaco_per_bin_encoder, [driver,native], 4000}, + {Codec, megaco_per_bin_encoder, [native], 3000}, + {Codec, megaco_per_bin_encoder, [driver], 3000}, + {Codec, megaco_per_bin_encoder, [], 1000}]; + erlang -> + [ + {Codec, megaco_erl_dist_encoder, [megaco_compressed,compressed], 500}, + {Codec, megaco_erl_dist_encoder, [compressed], 400}, + {Codec, megaco_erl_dist_encoder, [megaco_compressed], 10000}, + {Codec, megaco_erl_dist_encoder, [], 10000} + ]; + Else -> + exit({error, {invalid_codec, Else}}) + end. + + +measure_init([flex_scanner]) -> + start_flex_scanner(); +measure_init(Conf) -> + {undefined, Conf}. + + +measure_fin(Pid) when is_pid(Pid) -> + stop_flex_scanner(Pid), + ok; +measure_fin(_) -> + ok. + + +measure(_Dir, _Codec, _Conf, [], [], _MCount) -> + {error, no_messages}; + +measure(_Dir, _Codec, _Conf, [], Res, _MCount) -> + + Eavg = avg([Etime/Ecnt || #stat{ecount = Ecnt, etime = Etime} <- Res]), + Davg = avg([Dtime/Dcnt || #stat{dcount = Dcnt, dtime = Dtime} <- Res]), + Savg = avg([Size || #stat{size = Size} <- Res]), + + io:format("~n Measurment on ~p messages:" + "~n Average size: ~w bytes, " + "~n encode: ~w microsec, " + "~n decode: ~w microsec~n~n", + [length(Res), Savg, Eavg, Davg]), + + {ok, lists:reverse(Res)}; + +measure(Dir, Codec, Conf, [{Name, Bin}|Msgs], Results, MCount) -> + io:format(" ~p", [Name]), + case (catch do_measure(Dir, Codec, Conf, Name, Bin, MCount)) of + {ok, Stat} -> + measure(Dir, Codec, Conf, Msgs, [Stat | Results], MCount); + + {error, S} -> + io:format("~n~s failed: ~n", [Name]), + error(S,[]), + measure(Dir, Codec, Conf, Msgs, Results, MCount); + + {info, S} -> + case get(verbose) of + true -> + io:format("~n", []), + info(S,[]); + _ -> + io:format("~n~s skipped~n", [Name]) + end, + measure(Dir, Codec, Conf, Msgs, Results, MCount) + + end. + + +do_measure(_Id, Codec, Conf, Name, BinMsg, MCount) -> + %% io:format("~n~s~n", [binary_to_list(BinMsg)]), + {Version, NewBin} = detect_version(Codec, Conf, BinMsg), + {Msg, Dcnt, Dtime} = measure_decode(Codec, Conf, Version, NewBin, MCount), + {_, Ecnt, Etime} = measure_encode(Codec, Conf, Version, Msg, MCount), + + {ok, #stat{name = Name, + ecount = Ecnt, etime = Etime, + dcount = Dcnt, dtime = Dtime, + size = size(NewBin)}}. + +detect_version(Codec, Conf, Bin) -> + case (catch Codec:version_of(Conf, Bin)) of + {ok, V} -> + io:format("[~w]", [V]), + {ok, M} = Codec:decode_message(Conf, V, Bin), + {ok, NewBin} = Codec:encode_message(Conf, V, M), + io:format("[~w]", [size(NewBin)]), + {V, NewBin}; + Error -> + io:format("~nversion detection failed:~n~p", [Error]), + Error + end. + + +measure_decode(Codec, Conf, Version, Bin, MCount) -> + case measure_codec(Codec, decode_message, Conf, Version, Bin, MCount) of + {ok, Res} -> + Res; + {error, Reason} -> + S = format("decode failed for ~p:~n~p", [Codec, Reason]), + throw({error, S}) + end. + +measure_encode(Codec, Conf, Version, Bin, MCount) -> + case measure_codec(Codec, encode_message, Conf, Version, Bin, MCount) of + {ok, Res} -> + Res; + {error, Reason} -> + S = format("encode failed for ~p:~n~p", [Codec, Reason]), + throw({error, S}) + end. + + +measure_codec(Codec, Func, Conf, Version, Bin, MCount) -> + Pid = spawn_link(?MODULE, do_measure_codec, + [self(), Codec, Func, Conf, Version, Bin, MCount]), + receive + {measure_result, Pid, Func, Res} -> + {ok, Res}; + {error, Pid, Error} -> + {error, Error}; + Else -> + {error, {unexpected_result, Else}} + after ?MEASURE_TIMEOUT -> + Info = + case (catch process_info(Pid)) of + I when is_list(I) -> + exit(Pid, kill), + I; + _ -> + undefined + end, + {error, {timeout, MCount, Info}} + end. + + +do_measure_codec(Parent, Codec, Func, Conf, Version, Bin, MCount) -> + {ok, Count} = measure_warmup(Codec, Func, Conf, Version, Bin, MCount), + Res = timer:tc(?MODULE, do_measure_codec_loop, + [Codec, Func, Conf, Version, Bin, Count, dummy]), + case Res of + {Time, {ok, M}} -> + %% io:format("~w ", [Time]), + Parent ! {measure_result, self(), Func, {M, Count, Time}}; + {_Time, Error} -> + Parent ! {error, self(), Error} + end, + unlink(Parent). % Make sure Parent don't get our exit signal + + +%% This function does more mor less what the real measure function +%% above does. But with the diff: +%% 1) Warmup to ensure that all used code are loaded +%% 2) To aproximate the encoding time, to ensure that +%% the real encode is done with enough iterations. +measure_warmup(Codec, Func, Conf, Version, M, MCount) -> + Res = timer:tc(?MODULE, do_measure_codec_loop, + [Codec, Func, Conf, Version, M, MCount, dummy]), + case Res of + {Time, {ok, _}} -> + %% OK so far, now calculate the count: + Count = round(?MEASURE_COUNT_TIME/(Time/MCount)), + %% io:format("~w ", [Count]), + {ok, Count}; + {_Time, Error} -> + {error, {warmup_failed, Error}} + end. + + +do_measure_codec_loop(_Codec, _Func, _Conf, _Version, _Bin, 0, M) -> + {ok, M}; +do_measure_codec_loop(Codec, Func, Conf, Version, Bin, Count, _) -> + {ok, M} = apply(Codec, Func, [Conf, Version, Bin]), + do_measure_codec_loop(Codec, Func, Conf, Version, Bin, Count - 1, M). + + +%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%% + +store_results(Results) -> + io:format("storing: ~n", []), + store_excel_message_size(Results), + store_excel_decode_time(Results), + store_excel_encode_time(Results), + store_excel_total_time(Results), + io:format("~n", []), + ok. + + +store_excel_message_size(Res) -> + Filename = "message_size.xls", + io:format(" creating ~s~n", [Filename]), + {ok, Fd} = file:open(Filename,[write]), + Sizes = message_sizes(Res, []), + store_excel_tab(Fd, Sizes), + ok. + +store_excel_decode_time(Res) -> + Filename = "decode_time.xls", + io:format(" creating ~s~n", [Filename]), + {ok, Fd} = file:open(Filename,[write]), + Decodes = dec_times(Res, []), + store_excel_tab(Fd, Decodes), + ok. + +store_excel_encode_time(Res) -> + Filename = "encode_time.xls", + io:format(" creating ~s~n", [Filename]), + {ok, Fd} = file:open(Filename,[write]), + Encodes = enc_times(Res, []), + store_excel_tab(Fd, Encodes), + ok. + +store_excel_total_time(Res) -> + Filename = "total_time.xls", + io:format(" creating ~s~n", [Filename]), + {ok, Fd} = file:open(Filename,[write]), + Totals = tot_times(Res, []), + store_excel_tab(Fd, Totals), + ok. + + +message_sizes([], Sizes) -> + lists:reverse(Sizes); +message_sizes([{Dir, Conf, Res}|T], Acc) -> + Sizes = [Size || #stat{size = Size} <- Res], + Avg = avg(Sizes), + message_sizes(T, [{Dir, Conf, Avg, Sizes}|Acc]). + +dec_times([], Times) -> + lists:reverse(Times); +dec_times([{Dir, Conf, Res}|T], Acc) -> + Times = [Time/Count || #stat{dcount = Count, dtime = Time} <- Res], + Avg = avg(Times), + dec_times(T, [{Dir, Conf, Avg, Times}|Acc]). + +enc_times([], Times) -> + lists:reverse(Times); +enc_times([{Dir, Conf, Res}|T], Acc) -> + Times = [Time/Count || #stat{ecount = Count, etime = Time} <- Res], + Avg = avg(Times), + enc_times(T, [{Dir, Conf, Avg, Times}|Acc]). + +tot_times([], Times) -> + lists:reverse(Times); +tot_times([{Dir, Conf, Res}|T], Acc) -> + Times = [(Etime/Ecnt)+(Dtime/Dcnt) || #stat{ecount = Ecnt, + etime = Etime, + dcount = Dcnt, + dtime = Dtime} <- Res], + Avg = avg(Times), + tot_times(T, [{Dir, Conf, Avg, Times}|Acc]). + + +avg(Vals) -> + round(lists:sum(Vals)/length(Vals)). + + +store_excel_tab(_Fd, []) -> + ok; % Just in case there was something wrong with the test +store_excel_tab(Fd, Res) -> + %% For all elements of this list, the Values is of the same length... + [{_, _, _, Values}|_] = Res, + store_excel_tab_header(Fd, length(Values), 1), + store_excel_tab1(Fd, Res). + +store_excel_tab1(Fd, []) -> + io:format(Fd, "~n", []); +store_excel_tab1(Fd, [{Dir, Conf, Avg, Values}|T]) when is_list(Conf) -> + io:format(Fd, "~s~s (~w)", + [filename:basename(Dir), config_to_string(Conf), Avg]), + store_excel_tab_row(Fd, Values), + store_excel_tab1(Fd, T). + +config_to_string([]) -> + ""; +config_to_string([C]) when is_atom(C) -> + io_lib:format("_~w", [C]); +config_to_string([C|Cs]) when is_atom(C) -> + lists:flatten(io_lib:format("_~w", [C]) ++ config_to_string(Cs)). + +store_excel_tab_header(Fd, 0, _) -> + io:format(Fd, "~n", []); +store_excel_tab_header(Fd, N, M) -> + io:format(Fd, "\t~w", [M]), + store_excel_tab_header(Fd, N-1, M+1). + +store_excel_tab_row(Fd, []) -> + io:format(Fd, "~n", []); +store_excel_tab_row(Fd, [Value|Values]) -> + io:format(Fd, "\t~w", [round(Value)]), + store_excel_tab_row(Fd, Values). + + + + +%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%% + +start_flex_scanner() -> + Pid = proc_lib:spawn(?MODULE, flex_scanner_handler, [self()]), + receive + {flex_scanner_started, Pid, Conf} -> + {Pid, [Conf]}; + {flex_scanner_error, {failed_loading_flex_scanner_driver, Reason}} -> + throw({error, {failed_loading_flex_scanner_driver, Reason}}); + {flex_scanner_error, Reason} -> + throw({error, {failed_loading_flex_scanner_driver, Reason}}) + after 10000 -> + exit(Pid, kill), + throw({error, {failed_starting_flex_scanner, timeout}}) + end. + +stop_flex_scanner(Pid) -> + Pid ! stop_flex_scanner. + +flex_scanner_handler(Pid) -> + case (catch megaco_flex_scanner:start()) of + {ok, Port} when is_port(Port) -> + Pid ! {flex_scanner_started, self(), {flex, Port}}, + flex_scanner_handler(Pid, Port); + {ok, Ports} when is_tuple(Ports) -> + Pid ! {flex_scanner_started, self(), {flex, Ports}}, + flex_scanner_handler(Pid, Ports); + {error, {load_driver, {open_error, Reason}}} -> + Error = {failed_loading_flex_scanner_driver, Reason}, + Pid ! {flex_scanner_error, Error}, + exit(Error); + Else -> + Error = {unknown_result_from_start_flex_scanner, Else}, + Pid ! {flex_scanner_error, Error}, + exit(Error) + end. + +flex_scanner_handler(Pid, PortOrPorts) -> + receive + {ping, Pinger} -> + Pinger ! {pong, self()}, + flex_scanner_handler(Pid, PortOrPorts); + {'EXIT', Port, Reason} -> + case megaco_flex_scanner:is_scanner_port(Port, PortOrPorts) of + true -> + Pid ! {flex_scanner_exit, Reason}, + exit({flex_scanner_exit, Reason}); + false -> + info("exit signal from unknown port ~p" + "~n Reason: ~p", [Port, Reason]), + flex_scanner_handler(Pid, PortOrPorts) + end; + stop_flex_scanner -> + megaco_flex_scanner:stop(PortOrPorts), + exit(normal); + Other -> + info("flex scanner handler got something:~n~p", [Other]), + flex_scanner_handler(Pid, PortOrPorts) + end. + + +%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%% + +info(F, A) -> + io:format(F ++ "~n", A). + + +error(F, A) -> + io:format("ERROR: " ++ F ++ "~n", A). + + +format(F, A) -> + lists:flatten(io_lib:format(F, A)). -- cgit v1.2.3