From 6fe02e14d95e849d55d37d5449e835bcb8753da2 Mon Sep 17 00:00:00 2001 From: crownedgrouse Date: Sun, 27 Oct 2013 02:36:49 +0100 Subject: observer: Add SASL log view for processes Add a new menu to toggle log view. Disabled by default. Disabled if rb_server already started on observed node, in order not to interfere with somebody else. If enabled, add a tab in process view where log entries related to pid process are shown. Need an observed node with at least a version R16B2, due to the use of newly capability to rb to write into a file descriptor (on the observing node). --- lib/observer/doc/src/observer_ug.xml | 23 ++++++ lib/observer/src/observer_html_lib.erl | 8 ++- lib/observer/src/observer_procinfo.erl | 80 ++++++++++++++++++++- lib/observer/src/observer_wx.erl | 125 +++++++++++++++++++++++++++++---- lib/observer/test/observer_SUITE.erl | 35 +++++++-- 5 files changed, 248 insertions(+), 23 deletions(-) (limited to 'lib/observer') diff --git a/lib/observer/doc/src/observer_ug.xml b/lib/observer/doc/src/observer_ug.xml index 62f99c5210..fcb42f6c31 100644 --- a/lib/observer/doc/src/observer_ug.xml +++ b/lib/observer/doc/src/observer_ug.xml @@ -104,6 +104,29 @@

Reds can be presented as accumulated values or as values since last update.

 +

Process info open a detailed information window on the selected process. + + Process Information + Shows the process information. + Messages + Shows the process messages. + Dictionary + Shows the process dictionary. + Stack Trace + Shows the process current stack trace. + State + Show the process state. + Log + If enabled and available, show the process SASL log entries. + + +

Log needs SASL application to be started on the observed node, with log_mf_h as log handler. + The Observed node must be R16B02 or higher. + rb server must not be started on the observed node when clicking on menu 'Log/Toggle log view'. + rb server will be stopped on the observed node when exiting or changing observed node. +

+ +

Trace Processes will add the selected process identifiers to the Trace Overview view and the node the processes reside on will be added as well. Trace Named Processes will add the registered name of processes. This can be useful diff --git a/lib/observer/src/observer_html_lib.erl b/lib/observer/src/observer_html_lib.erl index c279218707..53197078cf 100644 --- a/lib/observer/src/observer_html_lib.erl +++ b/lib/observer/src/observer_html_lib.erl @@ -60,7 +60,8 @@ expandable_term_body(Heading,[],_Tab) -> "StackDump" -> "No stack dump was found"; "Dictionary" -> "No dictionary was found"; "ProcState" -> "Information could not be retrieved," - " system messages may not be handled by this process." + " system messages may not be handled by this process."; + "SaslLog" -> "No log entry was found" end]; expandable_term_body(Heading,Expanded,Tab) -> Attr = "BORDER=0 CELLPADDING=0 CELLSPACING=1 WIDTH=100%", @@ -102,7 +103,10 @@ expandable_term_body(Heading,Expanded,Tab) -> element(1, lists:mapfoldl(fun(Entry, Even) -> {proc_state(Tab, Entry,Even), not Even} - end, true, Expanded))]); + end, true, Expanded))]); + "SaslLog" -> + table(Attr, + [tr("BGCOLOR=white",[td("ALIGN=left", pre(href_proc_port(Expanded)))])]) ; _ -> table(Attr, [tr( diff --git a/lib/observer/src/observer_procinfo.erl b/lib/observer/src/observer_procinfo.erl index 8e8a37fc93..a8512894f9 100644 --- a/lib/observer/src/observer_procinfo.erl +++ b/lib/observer/src/observer_procinfo.erl @@ -43,6 +43,8 @@ -record(worker, {panel, callback}). +-record(io, {rdata=""}). + start(Process, ParentFrame, Parent) -> wx_object:start_link(?MODULE, [Process, ParentFrame, Parent], []). @@ -69,6 +71,10 @@ init([Pid, ParentFrame, Parent]) -> DictPage = init_panel(Notebook, "Dictionary", [Pid,Table], fun init_dict_page/3), StackPage = init_panel(Notebook, "Stack Trace", [Pid], fun init_stack_page/2), StatePage = init_panel(Notebook, "State", [Pid,Table], fun init_state_page/3), + Ps = case gen_server:call(observer, log_status) of + true -> [init_panel(Notebook, "Log", [Pid,Table], fun init_log_page/3)]; + false -> [] + end, wxFrame:connect(Frame, close_window), wxMenu:connect(Frame, command_menu_selected), @@ -78,7 +84,7 @@ init([Pid, ParentFrame, Parent]) -> pid=Pid, frame=Frame, notebook=Notebook, - pages=[ProcessPage,MessagePage,DictPage,StackPage,StatePage], + pages=[ProcessPage,MessagePage,DictPage,StackPage,StatePage|Ps], expand_table=Table }} catch error:{badrpc, _} -> @@ -327,6 +333,26 @@ fetch_state_info2(Pid, M) -> {badrpc,{'EXIT',{timeout, _}}} -> [] end. +init_log_page(Parent, Pid, Table) -> + Win = observer_lib:html_window(Parent), + Update = fun() -> + Fd = spawn_link(fun() -> io_server() end), + rpc:call(node(Pid), rb, rescan, [[{start_log, Fd}]]), + rpc:call(node(Pid), rb , grep, [local_pid_str(Pid)]), + Logs = io_get_data(Fd), + %% Replace remote local pid notation to global notation + Pref = global_pid_node_pref(Pid), + ExpPid = re:replace(Logs,"<0\.","<" ++ Pref ++ ".",[global, {return, list}]), + %% Try to keep same look by removing blanks at right of rewritten PID + NbBlanks = length(Pref) - 1, + Re = "(<" ++ Pref ++ "\.[^>]{1,}>)[ ]{"++ integer_to_list(NbBlanks) ++ "}", + Look = re:replace(ExpPid, Re, "\\1", [global, {return, list}]), + Html = observer_html_lib:expandable_term("SaslLog", Look, Table), + wxHtmlWindow:setPage(Win, Html) + end, + Update(), + {Win, Update}. + create_menus(MenuBar) -> Menus = [{"File", [#create_menu{id=?wxID_CLOSE, text="Close"}]}, {"View", [#create_menu{id=?REFRESH, text="Refresh\tCtrl-R"}]}], @@ -409,3 +435,55 @@ filter_monitor_info() -> Ms = proplists:get_value(monitors, Data), [Pid || {process, Pid} <- Ms] end. + +local_pid_str(Pid) -> + %% observer can observe remote nodes + %% There is no function to get the local + %% pid from the remote pid ... + %% So grep will fail to find remote pid in remote local log. + %% i.e. <4589.42.1> will not be found, but <0.42.1> will + %% Let's replace first integer by zero + "<0" ++ re:replace(pid_to_list(Pid),"\<([0-9]{1,})","",[{return, list}]). + +global_pid_node_pref(Pid) -> + %% Global PID node prefix : X of + string:strip(string:sub_word(pid_to_list(Pid),1,$.),left,$<). + + +io_get_data(Pid) -> + Pid ! {self(), get_data_and_close}, + receive + {Pid, data, Data} -> lists:flatten(Data) + end. + +io_server() -> + io_server(#io{}). + +io_server(State) -> + receive + {io_request, From, ReplyAs, Request} -> + case io_request(Request,State) of + {Tag, Reply, NewState} when Tag =:= ok; Tag =:= error -> + From ! {io_reply, ReplyAs, Reply}, + io_server(NewState); + {stop, Reply, _NewState} -> + From ! {io_reply, ReplyAs, Reply}, + exit(Reply) + end; + {Pid, get_data_and_close} -> + Pid ! {self(), data, lists:reverse(State#io.rdata)}, + normal; + _Unknown -> + io:format("~p: Unknown msg: ~p ~n",[?LINE, _Unknown]), + io_server(State) + end. + +io_request({put_chars, _Encoding, Chars}, State = #io{rdata=Data}) -> + {ok, ok, State#io{rdata=[Chars|Data]}}; +io_request({put_chars, Encoding, Module, Function, Args}, State) -> + try io_request({put_chars, Encoding, apply(Module, Function, Args)}, State) + catch _:_ -> {error, {error,Function}, State} + end; +io_request(Req, State) -> + io:format("~p: Unknown req: ~p ~n",[?LINE, Req]), + State. diff --git a/lib/observer/src/observer_wx.erl b/lib/observer/src/observer_wx.erl index c86f5ea916..54c4092a78 100644 --- a/lib/observer/src/observer_wx.erl +++ b/lib/observer/src/observer_wx.erl @@ -37,6 +37,7 @@ -define(ID_CONNECT, 2). -define(ID_NOTEBOOK, 3). -define(ID_CDV, 4). +-define(ID_LOGVIEW, 5). -define(FIRST_NODES_MENU_ID, 1000). -define(LAST_NODES_MENU_ID, 2000). @@ -60,7 +61,8 @@ active_tab, node, nodes, - prev_node="" + prev_node="", + log = false }). start() -> @@ -215,14 +217,17 @@ handle_event(#wx{event=#wxNotebook{type=command_notebook_page_changing}}, {noreply, State#state{active_tab=Pid}} end; -handle_event(#wx{event = #wxClose{}}, State) -> - {stop, normal, State}; - handle_event(#wx{id = ?ID_CDV, event = #wxCommand{type = command_menu_selected}}, State) -> spawn(crashdump_viewer, start, []), {noreply, State}; -handle_event(#wx{id = ?wxID_EXIT, event = #wxCommand{type = command_menu_selected}}, State) -> +handle_event(#wx{event = #wxClose{}}, #state{log=LogOn} = State) -> + LogOn andalso rpc:block_call(State#state.node, rb, stop, []), + {stop, normal, State}; + +handle_event(#wx{id = ?wxID_EXIT, event = #wxCommand{type = command_menu_selected}}, + #state{log=LogOn} = State) -> + LogOn andalso rpc:block_call(State#state.node, rb, stop, []), {stop, normal, State}; handle_event(#wx{id = ?wxID_HELP, event = #wxCommand{type = command_menu_selected}}, State) -> @@ -300,12 +305,42 @@ handle_event(#wx{id = ?ID_PING, event = #wxCommand{type = command_menu_selected} end, {noreply, UpdState}; -handle_event(#wx{id = Id, event = #wxCommand{type = command_menu_selected}}, State) - when Id > ?FIRST_NODES_MENU_ID, Id < ?LAST_NODES_MENU_ID -> +handle_event(#wx{id = ?ID_LOGVIEW, event = #wxCommand{type = command_menu_selected}}, + #state{frame = Frame, log = PrevLog, node = Node} = State) -> + try + ok = ensure_sasl_started(Node), + ok = ensure_mf_h_handler_used(Node), + ok = ensure_rb_mode(Node, PrevLog), + case PrevLog of + false -> + rpc:block_call(Node, rb, start, []), + set_status("Observer - " ++ atom_to_list(Node) ++ " (rb_server started)"), + {noreply, State#state{log=true}}; + true -> + rpc:block_call(Node, rb, stop, []), + set_status("Observer - " ++ atom_to_list(Node) ++ " (rb_server stopped)"), + {noreply, State#state{log=false}} + end + catch + throw:Reason -> + create_txt_dialog(Frame, Reason, "Log view status", ?wxICON_ERROR), + {noreply, State} + end; - Node = lists:nth(Id - ?FIRST_NODES_MENU_ID, State#state.nodes), - UpdState = change_node_view(Node, State), - {noreply, UpdState}; +handle_event(#wx{id = Id, event = #wxCommand{type = command_menu_selected}}, + #state{nodes= Ns , node = PrevNode, log = PrevLog} = State) + when Id > ?FIRST_NODES_MENU_ID, Id < ?LAST_NODES_MENU_ID -> + Node = lists:nth(Id - ?FIRST_NODES_MENU_ID, Ns), + %% Close rb_server only if another node than current one selected + LState = case PrevLog of + true -> case Node == PrevNode of + false -> rpc:block_call(PrevNode, rb, stop, []), + State#state{log=false} ; + true -> State + end; + false -> State + end, + {noreply, change_node_view(Node, LState)}; handle_event(Event, State) -> Pid = get_active_pid(State), @@ -340,6 +375,9 @@ handle_call(stop, _, State = #state{frame = Frame}) -> wxFrame:destroy(Frame), {stop, normal, ok, State}; +handle_call(log_status, _From, State) -> + {reply, State#state.log, State}; + handle_call(_Msg, _From, State) -> {reply, ok, State}. @@ -422,8 +460,7 @@ return_to_localnode(Frame, Node) -> end. create_txt_dialog(Frame, Msg, Title, Style) -> - MD = wxMessageDialog:new(Frame, Msg, [{style, Style}]), - wxMessageDialog:setTitle(MD, Title), + MD = wxMessageDialog:new(Frame, Msg, [{style, Style}, {caption,Title}]), wxDialog:showModal(MD), wxDialog:destroy(MD). @@ -569,17 +606,19 @@ default_menus(NodesMenuItems) -> false -> {"Nodes", NodesMenuItems ++ [#create_menu{id = ?ID_CONNECT, text = "Enable distribution"}]} end, + LogMenu = {"Log", [#create_menu{id = ?ID_LOGVIEW, text = "Toggle log view"}]}, case os:type() =:= {unix, darwin} of false -> FileMenu = {"File", [CDV, Quit]}, HelpMenu = {"Help", [About,Help]}, - [FileMenu, NodeMenu, HelpMenu]; + [FileMenu, NodeMenu, LogMenu, HelpMenu]; true -> %% On Mac quit and about will be moved to the "default' place %% automagicly, so just add them to a menu that always exist. %% But not to the help menu for some reason - {Tag, Menus} = FileMenu, - [{Tag, Menus ++ [About]}, NodeMenu, {"&Help", [Help]}] + + {Tag, Menus} = NodeMenu, + [{Tag, Menus ++ [Quit,About]}, LogMenu, {"&Help", [Help]}] end. clean_menus(Menus, MenuBar) -> @@ -658,3 +697,59 @@ update_node_list(State = #state{menubar=MenuBar}) -> end, observer_lib:create_menu_item(Dist, NodeMenu, Index), State#state{nodes = Nodes}. + +ensure_sasl_started(Node) -> + %% is sasl started ? + Apps = rpc:block_call(Node, application, which_applications, []), + case lists:keyfind(sasl, 1, Apps) of + false -> throw("Error: sasl application not started."), + error; + {sasl, _, _} -> ok + end. + +ensure_mf_h_handler_used(Node) -> + %% is log_mf_h used ? + Handlers = rpc:block_call(Node, gen_event, which_handlers, [error_logger]), + case lists:any(fun(L)-> L == log_mf_h end, Handlers) of + false -> throw("Error: log_mf_h handler not used in sasl."), + error; + true -> ok + end. + +ensure_rb_mode(Node, PrevLog) -> + ok = ensure_rb_module_loaded(Node), + ok = is_rb_compatible(Node), + ok = is_rb_server_running(Node, PrevLog), + ok. + + +ensure_rb_module_loaded(Node) -> + %% Need to ensure that module is loaded in order to detect exported + %% functions on interactive nodes + case rpc:block_call(Node, code, ensure_loaded, [rb]) of + {badrpc, Reason} -> + throw("Error: badrpc - " ++ io_lib:format("~tp",[Reason])); + {error, Reason} -> + throw("Error: rb module load error - " ++ io_lib:format("~tp",[Reason])); + {module,rb} -> + ok + end. + +is_rb_compatible(Node) -> + %% Simply test that rb:log_list/0 is exported + case rpc:block_call(Node, erlang, function_exported, [rb, log_list, 0]) of + false -> throw("Error: Node's Erlang release must be at least R16B02."); + true -> ok + end. + +is_rb_server_running(Node, LogState) -> + %% If already started, somebody else may use it. + %% We can not use it too, as far log file would be overriden. Not fair. + case rpc:block_call(Node, erlang, whereis, [rb_server]) of + Pid when is_pid(Pid), (LogState == false) -> + throw("Error: rb_server is already started and maybe used by someone."); + Pid when is_pid(Pid) -> + ok; + undefined -> + ok + end. diff --git a/lib/observer/test/observer_SUITE.erl b/lib/observer/test/observer_SUITE.erl index 5cf719acb1..c69fdf4bdf 100644 --- a/lib/observer/test/observer_SUITE.erl +++ b/lib/observer/test/observer_SUITE.erl @@ -22,6 +22,8 @@ -include_lib("wx/include/wx.hrl"). -include_lib("observer/src/observer_tv.hrl"). +-define(ID_LOGVIEW, 5). + %% Test server specific exports -export([all/0, suite/0,groups/0]). -export([init_per_testcase/2, end_per_testcase/2, @@ -44,8 +46,9 @@ all() -> groups() -> [{gui, [], - [basic - , process_win, table_win + [basic, + process_win, + table_win ] }]. @@ -107,7 +110,7 @@ appup_file(Config) when is_list(Config) -> basic(suite) -> []; basic(doc) -> [""]; basic(Config) when is_list(Config) -> - timer:send_after(100, "foobar"), %% Otherwise the timer sever gets added to procs + timer:send_after(100, "foobar"), %% Otherwise the timer server gets added to procs ProcsBefore = processes(), NumProcsBefore = length(ProcsBefore), @@ -126,7 +129,7 @@ basic(Config) when is_list(Config) -> timer:sleep(200), ok = wxNotebook:advanceSelection(Notebook) end, - %% Just verify that we can toogle trough all pages + %% Just verify that we can toggle through all pages [_|_] = [Check(N, false) || N <- lists:seq(1, Count)], %% Cause it to resize Frame = get_top_level_parent(Notebook), @@ -214,10 +217,27 @@ test_page(Title, Window) -> process_win(suite) -> []; process_win(doc) -> [""]; process_win(Config) when is_list(Config) -> + % Stop SASL if already started + SaslStart = case whereis(sasl_sup) of + undefined -> false; + _ -> application:stop(sasl), + true + end, + % Define custom sasl and log_mf_h app vars + Privdir=?config(priv_dir,Config), + application:set_env(sasl, sasl_error_logger, tty), + application:set_env(sasl, error_logger_mf_dir, Privdir), + application:set_env(sasl, error_logger_mf_maxbytes, 1000), + application:set_env(sasl, error_logger_mf_maxfiles, 5), + application:start(sasl), ok = observer:start(), ObserverNB = setup_whitebox_testing(), Parent = get_top_level_parent(ObserverNB), - Frame = observer_procinfo:start(self(), Parent, self()), + % Activate log view + whereis(observer) ! #wx{id = ?ID_LOGVIEW, event = #wxCommand{type = command_menu_selected}}, + timer:sleep(1000), + % Process window tests (use sasl_sup for a non empty Log tab) + Frame = observer_procinfo:start(whereis(sasl_sup), Parent, self()), PIPid = wx_object:get_pid(Frame), PIPid ! {get_debug_info, self()}, Notebook = receive {procinfo_debug, NB} -> NB end, @@ -229,6 +249,11 @@ process_win(Config) when is_list(Config) -> [_|_] = [Check(N) || N <- lists:seq(1, Count)], PIPid ! #wx{event=#wxClose{type=close_window}}, observer:stop(), + application:stop(sasl), + case SaslStart of + true -> application:start(sasl); + false -> ok + end, ok. table_win(suite) -> []; -- cgit v1.2.3