diff --git a/server/src/eflame.gleam b/server/src/eflame.gleam new file mode 100644 index 0000000..3a22483 --- /dev/null +++ b/server/src/eflame.gleam @@ -0,0 +1,2 @@ +@external(erlang, "eflame_ffi", "profile") +pub fn profile(name: String, fun: fn() -> a) -> a diff --git a/server/src/eflame_ffi.erl b/server/src/eflame_ffi.erl new file mode 100644 index 0000000..d6ed294 --- /dev/null +++ b/server/src/eflame_ffi.erl @@ -0,0 +1,195 @@ +%% Vendored from +%% +%% --- +%% +%% ISC License +%% +%% Copyright (c) 2014 Vladimir Kirillov +%% +%% Permission to use, copy, modify, and/or distribute this software for any +%% purpose with or without fee is hereby granted, provided that the above +%% copyright notice and this permission notice appear in all copies. +%% +%% THE SOFTWARE IS PROVIDED "AS IS" AND THE AUTHOR DISCLAIMS ALL WARRANTIES +%% WITH REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF +%% MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL THE AUTHOR BE LIABLE FOR +%% ANY SPECIAL, DIRECT, INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES +%% WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN +%% ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF +%% OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE. + +-module(eflame_ffi). +-export([profile/2, + apply/2, + apply/3, + apply/4, + apply/5]). + +-define(RESOLUTION, 1000). %% us +-record(dump, {stack=[], us=0, acc=[]}). % per-process state + +-define(DEFAULT_MODE, normal_with_children). +-define(DEFAULT_OUTPUT_FILE, "stacks.out"). + +profile(Name, Fun) -> + apply1(?DEFAULT_MODE, "flames/" ++ binary_to_list(Name) ++ ".out", {Fun, []}). + +apply(F, A) -> + apply1(?DEFAULT_MODE, ?DEFAULT_OUTPUT_FILE, {F, A}). + +apply(M, F, A) -> + apply1(?DEFAULT_MODE, ?DEFAULT_OUTPUT_FILE, {{M, F}, A}). + +apply(Mode, OutputFile, Fun, Args) -> + apply1(Mode, OutputFile, {Fun, Args}). + +apply(Mode, OutputFile, M, F, A) -> + apply1(Mode, OutputFile, {{M, F}, A}). + +apply1(Mode, OutputFile, {Fun, Args}) -> + Tracer = spawn_tracer(), + + start_trace(Tracer, self(), Mode), + Return = (catch apply_fun(Fun, Args)), + {ok, Bytes} = stop_trace(Tracer, self()), + + ok = file:write_file(OutputFile, Bytes), + Return. + +apply_fun({M, F}, A) -> + erlang:apply(M, F, A); +apply_fun(F, A) -> + erlang:apply(F, A). + +start_trace(Tracer, Target, Mode) -> + MatchSpec = [{'_', [], [{message, {{cp, {caller}}}}]}], + erlang:trace_pattern(on_load, MatchSpec, [local]), + erlang:trace_pattern({'_', '_', '_'}, MatchSpec, [local]), + erlang:trace(Target, true, [{tracer, Tracer} | trace_flags(Mode)]), + ok. + +stop_trace(Tracer, Target) -> + erlang:trace(Target, false, [all]), + Tracer ! {dump_bytes, self()}, + + Ret = receive {bytes, B} -> {ok, B} + after 5000 -> {error, timeout} + end, + + exit(Tracer, normal), + Ret. + +spawn_tracer() -> spawn(fun() -> trace_listener(dict:new()) end). + +trace_flags(normal) -> + [call, arity, return_to, timestamp, running]; +trace_flags(normal_with_children) -> + [call, arity, return_to, timestamp, running, set_on_spawn]; +trace_flags(like_fprof) -> % fprof does this as 'normal', will not work! + [call, return_to, running, procs, garbage_collection, arity, timestamp, set_on_spawn]. + +trace_listener(State) -> + receive + {dump, Pid} -> + Pid ! {stacks, dict:to_list(State)}; + {dump_bytes, Pid} -> + Bytes = iolist_to_binary([dump_to_iolist(TPid, Dump) || {TPid, [Dump]} <- dict:to_list(State)]), + Pid ! {bytes, Bytes}; + Term -> + trace_ts = element(1, Term), + PidS = element(2, Term), + + PidState = case dict:find(PidS, State) of + {ok, [Ps]} -> Ps; + error -> #dump{} + end, + + NewPidState = trace_proc_stream(Term, PidState), + + D1 = dict:erase(PidS, State), + D2 = dict:append(PidS, NewPidState, D1), + trace_listener(D2) + end. + +us({Mega, Secs, Micro}) -> + Mega*1000*1000*1000*1000 + Secs*1000*1000 + Micro. + +new_state(#dump{us=Us, acc=Acc} = State, Stack, Ts) -> + %io:format("new state: ~p ~p ~p~n", [Us, length(Stack), Ts]), + UsTs = us(Ts), + case Us of + 0 -> State#dump{us=UsTs, stack=Stack}; + _ when Us > 0 -> + Diff = us(Ts) - Us, + NOverlaps = Diff div ?RESOLUTION, + Overlapped = NOverlaps * ?RESOLUTION, + %Rem = Diff - Overlapped, + case NOverlaps of + X when X >= 1 -> + StackRev = lists:reverse(Stack), + Stacks = [StackRev || _ <- lists:seq(1, NOverlaps)], + State#dump{us=Us+Overlapped, acc=lists:append(Stacks, Acc), stack=Stack}; + _ -> + State#dump{stack=Stack} + end + end. + +trace_proc_stream({trace_ts, _Ps, call, MFA, {cp, {_,_,_} = CallerMFA}, Ts}, #dump{stack=[]} = State) -> + new_state(State, [MFA, CallerMFA], Ts); + +trace_proc_stream({trace_ts, _Ps, call, MFA, {cp, undefined}, Ts}, #dump{stack=[]} = State) -> + new_state(State, [MFA], Ts); + +trace_proc_stream({trace_ts, _Ps, call, MFA, {cp, undefined}, Ts}, #dump{stack=[MFA|_] = Stack} = State) -> + new_state(State, Stack, Ts); + +trace_proc_stream({trace_ts, _Ps, call, MFA, {cp, undefined}, Ts}, #dump{stack=Stack} = State) -> + new_state(State, [MFA | Stack], Ts); + +trace_proc_stream({trace_ts, _Ps, call, MFA, {cp, MFA}, Ts}, #dump{stack=[MFA|Stack]} = State) -> + new_state(State, [MFA|Stack], Ts); % collapse tail recursion + +trace_proc_stream({trace_ts, _Ps, call, MFA, {cp, CpMFA}, Ts}, #dump{stack=[CpMFA|Stack]} = State) -> + new_state(State, [MFA, CpMFA|Stack], Ts); + +trace_proc_stream({trace_ts, _Ps, call, _MFA, {cp, _}, _Ts} = TraceTs, #dump{stack=[_|StackRest]} = State) -> + trace_proc_stream(TraceTs, State#dump{stack=StackRest}); + +trace_proc_stream({trace_ts, _Ps, return_to, MFA, Ts}, #dump{stack=[_Current, MFA|Stack]} = State) -> + new_state(State, [MFA|Stack], Ts); % do not try to traverse stack down because we've already collapsed it + +trace_proc_stream({trace_ts, _Ps, return_to, undefined, _Ts}, State) -> + State; + +trace_proc_stream({trace_ts, _Ps, return_to, _, _Ts}, State) -> + State; + +trace_proc_stream({trace_ts, _Ps, in, _MFA, Ts}, #dump{stack=[sleep|Stack]} = State) -> + new_state(new_state(State, [sleep|Stack], Ts), Stack, Ts); + +trace_proc_stream({trace_ts, _Ps, in, _MFA, Ts}, #dump{stack=Stack} = State) -> + new_state(State, Stack, Ts); + +trace_proc_stream({trace_ts, _Ps, out, _MFA, Ts}, #dump{stack=Stack} = State) -> + new_state(State, [sleep|Stack], Ts); + +trace_proc_stream(TraceTs, State) -> + io:format("trace_proc_stream: unknown trace: ~p~n", [TraceTs]), + State. + +stack_collapse(Stack) -> + intercalate(";", [entry_to_iolist(S) || S <- Stack]). + +entry_to_iolist({M, F, A}) -> + [atom_to_binary(M, utf8), <<":">>, atom_to_binary(F, utf8), <<"/">>, integer_to_list(A)]; +entry_to_iolist(A) when is_atom(A) -> + [atom_to_binary(A, utf8)]. + +dump_to_iolist(Pid, #dump{acc=Acc}) -> + [[pid_to_list(Pid), <<";">>, stack_collapse(S), <<"\n">>] || S <- lists:reverse(Acc)]. + +intercalate(Sep, Xs) -> lists:concat(intersperse(Sep, Xs)). + +intersperse(_, []) -> []; +intersperse(_, [X]) -> [X]; +intersperse(Sep, [X | Xs]) -> [X, Sep | intersperse(Sep, Xs)]. diff --git a/server/src/subway_gleam/server.gleam b/server/src/subway_gleam/server.gleam index 82d2f61..7b2d457 100644 --- a/server/src/subway_gleam/server.gleam +++ b/server/src/subway_gleam/server.gleam @@ -1,3 +1,4 @@ +import eflame import gleam/erlang/process import gleam/float import gleam/http/request @@ -29,7 +30,6 @@ import subway_gleam/server/route/train import subway_gleam/server/sse_gtfs.{sse_gtfs} import subway_gleam/server/state import subway_gleam/server/state/gtfs_store -import subway_gleam/server/tprof import subway_gleam/shared/route/stop as shared_stop import subway_gleam/shared/route/train as shared_train @@ -181,12 +181,12 @@ fn handler(state: state.State, req: wisp.Request) -> wisp.Response { ["map"] -> route.map(req) ["stops"] -> case env.profile_pages() |> list.contains("stops") { - True -> tprof.tprof(fn() { route.stops(req, state) }) + True -> eflame.profile("stops", fn() { route.stops(req, state) }) False -> route.stops(req, state) } ["stop", stop_id] -> case env.profile_pages() |> list.contains("stop") { - True -> tprof.tprof(fn() { route.stop(req, state, stop_id) }) + True -> eflame.profile("stop", fn() { route.stop(req, state, stop_id) }) False -> route.stop(req, state, stop_id) } ["stop", _stop_id, "alerts"] -> @@ -196,14 +196,15 @@ fn handler(state: state.State, req: wisp.Request) -> wisp.Response { ["stop", stop_id, "alerts", route_id] -> case env.profile_pages() |> list.contains("stop_alerts") { True -> - tprof.tprof(fn() { + eflame.profile("stop_alerts", fn() { route.stop_alerts(req, state, stop_id, option.Some(route_id)) }) False -> route.stop_alerts(req, state, stop_id, option.Some(route_id)) } ["train", train_id] -> case env.profile_pages() |> list.contains("train") { - True -> tprof.tprof(fn() { route.train(req, state, train_id) }) + True -> + eflame.profile("train", fn() { route.train(req, state, train_id) }) False -> route.train(req, state, train_id) } ["line", route_id] -> route.line(req, state, route_id) diff --git a/server/src/subway_gleam/server/tprof.gleam b/server/src/subway_gleam/server/tprof.gleam deleted file mode 100644 index da268ea..0000000 --- a/server/src/subway_gleam/server/tprof.gleam +++ /dev/null @@ -1,2 +0,0 @@ -@external(erlang, "tprof_ffi", "tprof") -pub fn tprof(fun: fn() -> a) -> a diff --git a/server/src/subway_gleam/server/tprof_ffi.erl b/server/src/subway_gleam/server/tprof_ffi.erl deleted file mode 100644 index 825c5a1..0000000 --- a/server/src/subway_gleam/server/tprof_ffi.erl +++ /dev/null @@ -1,7 +0,0 @@ --module(tprof_ffi). --export([tprof/1]). - -tprof(F) -> - {Result, Data} = tprof:profile(F, #{type => call_time, report => return}), - tprof:format(tprof:inspect(Data)), - Result.