From 67dcbad65d602661d5c32e5be3af93f3975e323c Mon Sep 17 00:00:00 2001 From: andytill Date: Sat, 26 Aug 2017 20:18:19 +0000 Subject: [PATCH 01/10] Instead of tracing to a process, using a tracing port which opens a TCP server on the remote node which erlyberly connects into. Trace messages are then sent to this socket. --- src/main/java/erlyberly/DbgTraceView.java | 22 +- src/main/java/erlyberly/StackTraceView.java | 2 + src/main/java/erlyberly/TraceLog.java | 234 ++++++++++-------- .../erlyberly/format/ElixirFormatter.java | 2 +- .../java/erlyberly/format/TermFormatter.java | 3 + src/main/java/erlyberly/node/NodeAPI.java | 24 +- .../java/erlyberly/node/TraceFileReader.java | 41 +++ .../java/erlyberly/node/TraceManager.java | 63 ++--- .../erlyberly/node/TraceServerConnection.java | 93 +++++++ .../resources/erlyberly/beam/erlyberly.erl | 25 +- 10 files changed, 341 insertions(+), 168 deletions(-) create mode 100644 src/main/java/erlyberly/node/TraceFileReader.java create mode 100644 src/main/java/erlyberly/node/TraceServerConnection.java diff --git a/src/main/java/erlyberly/DbgTraceView.java b/src/main/java/erlyberly/DbgTraceView.java index 64ef94c..2a985bd 100644 --- a/src/main/java/erlyberly/DbgTraceView.java +++ b/src/main/java/erlyberly/DbgTraceView.java @@ -190,8 +190,9 @@ private void putTraceContextMenu() { private void onTraceClicked(MouseEvent me) { if(me.getButton().equals(MouseButton.PRIMARY) && me.getClickCount() == 2) { TraceLog selectedItem = tracesBox.getSelectionModel().getSelectedItem(); - - if(selectedItem != null && selectedItem != null) { + // some items may not traces, they might be node down messages for example + boolean isActualTrace = !"".equals(selectedItem.getArgs()); + if(selectedItem != null && selectedItem != null && isActualTrace) { showTraceTermView(selectedItem); } } @@ -217,14 +218,15 @@ private void showTraceTermView(final TraceLog traceLog) { resultTermsTreeView = newTermTreeView(); if(result != null) { - resultTermsTreeView.populateFromTerm(traceLog.getResultFromMap()); + resultTermsTreeView.populateFromTerm(result); } else { + // the result may be receievd while the term view is open so put a listen + // on the result property and show it if is set WeakChangeListener listener = new WeakChangeListener((o, oldV, newV) -> { if(newV) resultTermsTreeView.populateFromTerm(traceLog.getResultFromMap()); }); - traceLog.isCompleteProperty().addListener(listener); } @@ -242,9 +244,15 @@ private void showTraceTermView(final TraceLog traceLog) { StackTraceView stackTraceView; stackTraceView = new StackTraceView(); - stackTraceView.populateFromMfaList(traceLog.getStackTrace()); - String stackTraceTitle = "Stack Trace (" + traceLog.getStackTrace().arity() + ")"; - TitledPane titledPane = new TitledPane(stackTraceTitle, stackTraceView); + + String stackTraceTitle = "No Stack Trace"; + OtpErlangList stackTrace = traceLog.getStackTrace(); + if(stackTrace != null) { + stackTraceView.populateFromMfaList(stackTrace); + stackTraceTitle = "Stack Trace (" + stackTrace.arity() + ")"; + } + TitledPane titledPane; + titledPane = new TitledPane(stackTraceTitle, stackTraceView); titledPane.setExpanded(!stackTraceView.isStackTracesEmpty()); splitPaneH = new SplitPane(); splitPaneH.setOrientation(Orientation.VERTICAL); diff --git a/src/main/java/erlyberly/StackTraceView.java b/src/main/java/erlyberly/StackTraceView.java index 0130065..7a55dc7 100644 --- a/src/main/java/erlyberly/StackTraceView.java +++ b/src/main/java/erlyberly/StackTraceView.java @@ -107,6 +107,8 @@ private ModFunc mfaToModFunc(OtpErlangAtom module, OtpErlangAtom function, OtpEr } public void populateFromMfaList(OtpErlangList stackTrace) { + if(stackTrace == null) + return; try { for (OtpErlangObject obj : stackTrace) { if(obj instanceof OtpErlangString) { diff --git a/src/main/java/erlyberly/TraceLog.java b/src/main/java/erlyberly/TraceLog.java index 37754ff..de13ca8 100644 --- a/src/main/java/erlyberly/TraceLog.java +++ b/src/main/java/erlyberly/TraceLog.java @@ -17,19 +17,18 @@ */ package erlyberly; -import java.util.HashMap; -import java.util.Map; +import static erlyberly.node.OtpUtil.atom; + import java.util.concurrent.atomic.AtomicLong; import com.ericsson.otp.erlang.OtpErlangAtom; import com.ericsson.otp.erlang.OtpErlangList; import com.ericsson.otp.erlang.OtpErlangLong; import com.ericsson.otp.erlang.OtpErlangObject; -import com.ericsson.otp.erlang.OtpErlangString; +import com.ericsson.otp.erlang.OtpErlangPid; import com.ericsson.otp.erlang.OtpErlangTuple; -import erlyberly.node.OtpUtil; -import javafx.application.Platform; +import erlyberly.format.TermFormatter; import javafx.beans.property.ReadOnlyBooleanProperty; import javafx.beans.property.SimpleBooleanProperty; import javafx.beans.property.SimpleLongProperty; @@ -37,19 +36,16 @@ public class TraceLog implements Comparable { - private static final OtpErlangAtom FN_ATOM = new OtpErlangAtom("fn"); - public static final OtpErlangAtom EXCEPTION_FROM_ATOM = new OtpErlangAtom("exception_from"); + private static final OtpErlangAtom EXCEPTION_FROM = atom("exception_from"); + public static final OtpErlangAtom TRACE_TS = atom("trace_ts"); + public static final OtpErlangAtom FN_ATOM = new OtpErlangAtom("fn"); public static final OtpErlangAtom RESULT_ATOM = new OtpErlangAtom("result"); - public static final OtpErlangAtom ATOM_PID = new OtpErlangAtom("pid"); + public static final OtpErlangAtom PID_ATOM = new OtpErlangAtom("pid"); public static final OtpErlangAtom ATOM_REG_NAME = new OtpErlangAtom("reg_name"); - public static final OtpErlangAtom ATOM_UNDEFINED = new OtpErlangAtom("undefined"); - private static final Object TIMESTAMP_CALL_ATOM = new OtpErlangAtom("timetamp_call_us"); - private static final Object TIMESTAMP_RETURN_ATOM = new OtpErlangAtom("timetamp_return_us"); + public static final OtpErlangAtom UNDEFINED_ATOM = new OtpErlangAtom("undefined"); private static final AtomicLong INSTANCE_COUNTER = new AtomicLong(); - private final Map map; - private final long instanceNum; private final SimpleStringProperty summary = new SimpleStringProperty(""); @@ -60,43 +56,100 @@ public class TraceLog implements Comparable { private final SimpleBooleanProperty complete = new SimpleBooleanProperty(false); - private String tracePropsToString; + private final String pidString, argsString, functionString; - private final String pid, registeredName, function, argsString; + private final OtpErlangPid pid; private final String cssClass; - public TraceLog(Map map) { - this.map = map; + // FIXME registeredName + private String registeredName = ""; + + private OtpErlangList stacktrace; + + private boolean functionThrewException; + + private ModFunc modFunc; + + /** + * The timestamp in microseconds of when the function was called. + */ + private long callTime; + + private OtpErlangList args; + + private OtpErlangObject resultTerm; + + public TraceLog(OtpErlangTuple tuple, TermFormatter formatter) { instanceNum = INSTANCE_COUNTER.incrementAndGet(); - pid = getPidString(); - registeredName = regNameString().intern(); - function = appendModFuncArity(new StringBuilder()).toString().intern(); - argsString = appendArgsToString(new StringBuilder(), getArgsList().elements()).toString(); cssClass = null; + // FIXME we don't know the registered name from the info we get from the file + // may have to get the registered names from tracing registrations + // http://erlang.org/doc/man/erlang.html#trace_3_trace_messages_register + // {trace_ts,<0.79.0>,call,{code,all_loaded,[]},{1502,734505,108159}} + OtpErlangObject messageType = tuple.elementAt(0); + assert TRACE_TS.equals(messageType) : messageType; + assert tuple.elementAt(1) instanceof OtpErlangPid : tuple.elementAt(1); + pid = (OtpErlangPid) tuple.elementAt(1); + pidString = formatter.toString(tuple.elementAt(1)); + // we only accept trace types of `call` in the constructor + OtpErlangObject traceType = tuple.elementAt(2); + assert traceType instanceof OtpErlangAtom : traceType; + assert traceType.equals(atom("call")) : traceType; + OtpErlangObject mfaObject = tuple.elementAt(3); + assert mfaObject instanceof OtpErlangTuple : mfaObject; + OtpErlangTuple mfa = (OtpErlangTuple) mfaObject; + assert mfa.arity() == 3 : mfa; + assert mfa.elementAt(0) instanceof OtpErlangAtom : mfa; + assert mfa.elementAt(1) instanceof OtpErlangAtom : mfa; + assert mfa.elementAt(2) instanceof OtpErlangList : mfa; + args = (OtpErlangList) mfa.elementAt(2); + argsString = appendArgsToString(new StringBuilder(), getArgsList().elements()).toString(); + int arity = args.arity(); + modFunc = new ModFunc( + ((OtpErlangAtom)mfa.elementAt(0)).atomValue(), + ((OtpErlangAtom)mfa.elementAt(1)).atomValue(), arity, false, false); + // the three element tuple timestamp + assert tuple.elementAt(4) instanceof OtpErlangTuple : "TRACE WAS " + tuple + " timestamp was " + formatter.toString(tuple.elementAt(4)); + callTime = tupleToTimestamp((OtpErlangTuple) tuple.elementAt(4)); + functionString = formatter.modFuncArityToString( + modFunc.getModuleName(), modFunc.getFuncName(), modFunc.getArity()); + + } + + /** + * Convert the annoying erlang 3 element timestamp to microseconds. + */ + private long tupleToTimestamp(OtpErlangTuple tuple) { + assert tuple.arity() == 3; + long mega, sec, micros; + mega = tupleElementToLong(0, tuple); + sec = tupleElementToLong(1, tuple); + micros = tupleElementToLong(2, tuple); + return (((mega * 1000000) + sec) * 1000000) + micros; + } + + private long tupleElementToLong(int index, OtpErlangTuple tuple) { + assert index < tuple.arity() : tuple; + assert tuple.elementAt(index) instanceof OtpErlangLong; + return ((OtpErlangLong)tuple.elementAt(index)).longValue(); } public TraceLog(String aCssClass, String text) { - function = text; instanceNum = INSTANCE_COUNTER.incrementAndGet(); - map = new HashMap<>(0); cssClass = aCssClass; - pid = ""; + pidString = ""; registeredName = ""; argsString = ""; + pid = null; + // this is what shows up in the table + functionString = text; } public long getInstanceNum() { return instanceNum; } - private String regNameString() { - Object object = map.get(ATOM_REG_NAME); - if(ATOM_UNDEFINED.equals(object)) - return ""; - return object.toString(); - } - public SimpleStringProperty summaryProperty() { if(summary.get().isEmpty()) { summary.set(toString()); @@ -104,14 +157,7 @@ public SimpleStringProperty summaryProperty() { return summary; } - @Override - public String toString() { - if(tracePropsToString == null) - tracePropsToString = tracePropsToString(); - return tracePropsToString; - } - - private String tracePropsToString() { +/* private String tracePropsToString() { StringBuilder sb = new StringBuilder(1024); boolean appendArity = false; @@ -129,64 +175,30 @@ else if(isExceptionThrower()) { ); } return sb.toString(); - } + }*/ private StringBuilder toCallString(StringBuilder sb, boolean appendArity) { - OtpErlangAtom regName = (OtpErlangAtom) map.get(ATOM_REG_NAME); - - if(regName != null && !ATOM_UNDEFINED.equals(regName)) { - sb.append(regName.atomValue()); + if(!"".equals(registeredName)) { + sb.append(registeredName); } else { - OtpErlangString pidString = (OtpErlangString) map.get(ATOM_PID); - if(pidString == null) - sb.append(""); - else - sb.append(pidString.stringValue()); + sb.append(pidString); } sb.append(" "); - sb.append("+").append(durationFromMap()).append("us"); + sb.append("+").append(duration).append("us"); appendModFuncArity(sb); return sb; } - private long durationFromMap() { - Object tsCall = map.get(TIMESTAMP_CALL_ATOM); - Object tsReturn = map.get(TIMESTAMP_RETURN_ATOM); - - if(tsCall == null|| tsReturn == null) - return 0; - - return ((OtpErlangLong)tsReturn).longValue() - ((OtpErlangLong)tsCall).longValue(); - } - - /** - * Returns an MFA. - */ - private OtpErlangTuple getFunctionFromMap() { - return (OtpErlangTuple)map.get(FN_ATOM); - } - public boolean isExceptionThrower() { - return map.containsKey(EXCEPTION_FROM_ATOM); - } - - public StringBuilder appendFunctionToString(StringBuilder sb) { - OtpErlangTuple tuple = getFunctionFromMap(); - - return sb.append(ErlyBerly.getTermFormatter().modFuncArgsToString(tuple)); + return functionThrewException; } public StringBuilder appendModFuncArity(StringBuilder sb) { - OtpErlangTuple fn = getFunctionFromMap(); - // there might be no function if this TraceLog is acting as a NODE DOWN - if(fn == null) { - return sb; - } - return sb.append(ErlyBerly.getTermFormatter().modFuncArityToString(fn)); + return sb.append(functionString); } private StringBuilder appendArgsToString(StringBuilder sb, OtpErlangObject[] elements) { @@ -201,19 +213,11 @@ private StringBuilder appendArgsToString(StringBuilder sb, OtpErlangObject[] ele } public OtpErlangList getArgsList() { - OtpErlangTuple tuple = getFunctionFromMap(); - OtpErlangList args = OtpUtil.toOtpList(tuple.elementAt(2)); return args; } - public String getPidString() { - OtpErlangString s = (OtpErlangString)map.get(ATOM_PID); - - return s.stringValue(); - } - public OtpErlangObject getResultFromMap() { - Object object = map.get(RESULT_ATOM); + /* Object object = map.get(RESULT_ATOM); if(object == null) { OtpErlangTuple exception = (OtpErlangTuple) map.get(EXCEPTION_FROM_ATOM); @@ -221,7 +225,8 @@ public OtpErlangObject getResultFromMap() { return exception.elementAt(1); } } - return (OtpErlangObject) object; + return (OtpErlangObject) object;*/ + return resultTerm; } @Override @@ -229,8 +234,11 @@ public int compareTo(TraceLog o) { return Long.compare(instanceNum, o.instanceNum); } - public void complete(Map resultMap) { - tracePropsToString = null; + /** + * Called when we get a return_from trace which completes t + */ + public void complete(OtpErlangTuple tuple, TermFormatter formatter) { +/* Object e = resultMap.get(EXCEPTION_FROM_ATOM); Object ts = resultMap.get(TIMESTAMP_RETURN_ATOM); Object r = resultMap.get(RESULT_ATOM); @@ -251,7 +259,24 @@ public void complete(Map resultMap) { duration.set(durationFromMap()); - Platform.runLater(() -> { summary.set(toString()); complete.set(true); }); + Platform.runLater(() -> { summary.set(toString()); complete.set(true); });*/ + + // {trace_ts,#Pid,return_from,{code,module_info,1},[{objfile_extension,0},{load_file,1},{ensure_loaded,1},{load_abs,1},{load_abs,2},{load_binary,3},{load_native_partial,2},{load_native_sticky,3},{delete,1},{purge,1},{soft_purge,1},{is_loaded,1},{get_object_code,1},{all_loaded,0},{stop,0},{root_dir,0},{lib_dir,0},{lib_dir,1},{lib_dir,2},{compiler_dir,0},{priv_dir,1},{stick_dir,1},{unstick_dir,1},{stick_mod,1},{unstick_mod,1},{is_sticky,1},{set_path,1},{get_path,0},{add_path,1},{add_pathz,1},{add_patha,1},{add_paths,1},{add_pathsz,1},{add_pathsa,1},{del_path,1},{replace_path,2},{rehash,0},{get_mode,0},{call,1},{start_link,0},{start_link,1},{do_start,1},{load_code_server_prerequisites,0},{do_stick_dirs,0},{do_s,1},{get_mode,1},{which,1},{which2,1},{which,3},{where_is_file,1},{where_is_file,2},{set_primary_archive,4},{clash,0},{search,1},{build,1},{decorate,2},{filter,3},{filter2,3},{has_ext,3},{load_native_code_for_all_loaded,0},{module_info,0},{module_info,1},{'-load_native_code_for_all_loaded/0-fun-0-',2},{'-set_primary_archive/4-lc$^0/1-0-',2},{'-load_code_server_prerequisites/0-lc$^0/1-0-',1}],{1502,773031,999016}} + + assert TRACE_TS.equals(tuple.elementAt(0)); + assert tuple.elementAt(1) instanceof OtpErlangPid : tuple; + assert pid.equals(tuple.elementAt(1)) : tuple; + assert tuple.elementAt(2) instanceof OtpErlangAtom : tuple; + OtpErlangAtom traceType = (OtpErlangAtom) tuple.elementAt(2); + assert atom("return_from").equals(traceType) || EXCEPTION_FROM.equals(traceType) : tuple; + functionThrewException = EXCEPTION_FROM.equals(traceType); + // index 3 is the mfa which we already have from the call trace message + resultTerm = tuple.elementAt(4); + result.set(formatter.toString(resultTerm)); + OtpErlangTuple tsTuple = (OtpErlangTuple) tuple.elementAt(5); + long returnTs = tupleToTimestamp(tsTuple); + duration.set(returnTs - callTime); + complete.set(true); } public ReadOnlyBooleanProperty isCompleteProperty() { @@ -271,7 +296,7 @@ public String toCallString() { return toCallString(sb, appendArity).toString(); } - public String getPid() { + public OtpErlangPid getPid() { return pid; } @@ -287,10 +312,6 @@ public SimpleLongProperty durationProperty() { return duration; } - public String getFunction() { - return function; - } - public String getArgs() { return argsString; } @@ -320,17 +341,18 @@ public static TraceLog newLoadShedding() { } public OtpErlangList getStackTrace() { - OtpErlangList stacktrace = (OtpErlangList) map.get(OtpUtil.atom("stack_trace")); - if(stacktrace == null) - stacktrace = new OtpErlangList(); return stacktrace; } public ModFunc getModFunc() { - OtpErlangTuple mfa = getFunctionFromMap(); - OtpErlangAtom module = (OtpErlangAtom) mfa.elementAt(0); - OtpErlangAtom function = (OtpErlangAtom) mfa.elementAt(1); - int arity = ((OtpErlangList) mfa.elementAt(2)).arity(); - return new ModFunc(module.atomValue(), function.atomValue(), arity, false, false); + return modFunc; + } + + public String getPidString() { + return pidString; + } + + public String getFunction() { + return functionString; } } diff --git a/src/main/java/erlyberly/format/ElixirFormatter.java b/src/main/java/erlyberly/format/ElixirFormatter.java index 3f21f79..2c35cc5 100644 --- a/src/main/java/erlyberly/format/ElixirFormatter.java +++ b/src/main/java/erlyberly/format/ElixirFormatter.java @@ -212,7 +212,7 @@ private String moduleNameToString(OtpErlangAtom mod) { @Override public String moduleNameToString(String moduleName) { if(moduleName.startsWith("Elixir.")) - return moduleName.substring(7); + return moduleName.substring("Elixir.".length()); else return ":" + moduleName; } diff --git a/src/main/java/erlyberly/format/TermFormatter.java b/src/main/java/erlyberly/format/TermFormatter.java index 18f3ef0..1388657 100644 --- a/src/main/java/erlyberly/format/TermFormatter.java +++ b/src/main/java/erlyberly/format/TermFormatter.java @@ -29,6 +29,9 @@ public interface TermFormatter { String modFuncArgsToString(OtpErlangTuple mfa); + /** + * For example mymod:myfunc/2 in an erlang implementation. + */ String modFuncArityToString(OtpErlangTuple mfa); default String modFuncArityToString(String mod, String func, int arity) { return mod + ":" + func + "/" + arity; } diff --git a/src/main/java/erlyberly/node/NodeAPI.java b/src/main/java/erlyberly/node/NodeAPI.java index 4a174e5..e3421c5 100644 --- a/src/main/java/erlyberly/node/NodeAPI.java +++ b/src/main/java/erlyberly/node/NodeAPI.java @@ -125,19 +125,14 @@ public class NodeAPI { private RpcCallback moduleLoadedCallback; - /** - * Called when a trace log is received. - *
- * Should only accessed from the FX thread. - */ - private RpcCallback traceLogCallback; - /** * When tracing is paused, NodeAPI will stop all traces. When tracing is un-suspended * the DbgController must reapply all the traces. */ private final SimpleBooleanProperty suspendedProperty; + private TraceServerConnection traceServerConnection; + public NodeAPI() { traceManager = new TraceManager(); @@ -228,6 +223,9 @@ public synchronized void connect() throws IOException, OtpErlangException, OtpAu checkAliveThread = new CheckAliveThread(); checkAliveThread.start(); } + + traceServerConnection = new TraceServerConnection(traceManager); + traceServerConnection.connect("localhost", 7777); } public void manuallyDisconnect() throws IOException, OtpErlangException { @@ -265,7 +263,9 @@ public void disconnect() { } private synchronized void ensureDbgStarted() throws IOException, OtpErlangException { - OtpErlangList argList = list(tuple(atom(self.node()), mbox.self()), PrefBind.getMaxTraceQueueLengthConfig()); + int maxQueueLen = PrefBind.getMaxTraceQueueLengthConfig(); + int serverPort = 7777; + OtpErlangList argList = list(tuple(atom(self.node()), mbox.self()), serverPort, maxQueueLen); OtpErlangObject returnedObject = nodeRPC() .blockingRPC(ERLYBERLY_ATOM, atom("ensure_dbg_started"), argList); // the return should be {ok, TracerPid} @@ -431,7 +431,7 @@ private void unloadRemoteErlyberly() throws IOException, OtpErlangException { } private void traceLogNotification(OtpErlangTuple receive) { - Platform.runLater(() -> { + /* Platform.runLater(() -> { OtpErlangTuple traceLog = (OtpErlangTuple) receive.elementAt(1); List collatedTraces = traceManager.collateTraceSingle(traceLog); if(traceLogCallback != null) { @@ -439,7 +439,7 @@ private void traceLogNotification(OtpErlangTuple receive) { traceLogCallback.callback(log); } } - }); + });*/ } private static byte[] loadBeamFile() throws IOException { @@ -760,11 +760,11 @@ public void loadModule(OtpErlangAtom moduleNameAtom) throws OtpErlangException, } public RpcCallback getTraceLogCallback() { - return traceLogCallback; + return traceManager.getTraceLogCallback(); } public void setTraceLogCallback(RpcCallback traceLogCallback) { - this.traceLogCallback = traceLogCallback; + traceManager.setTraceLogCallback(traceLogCallback); } public void toggleSuspended() throws OtpErlangException, IOException { diff --git a/src/main/java/erlyberly/node/TraceFileReader.java b/src/main/java/erlyberly/node/TraceFileReader.java new file mode 100644 index 0000000..fee27a8 --- /dev/null +++ b/src/main/java/erlyberly/node/TraceFileReader.java @@ -0,0 +1,41 @@ +package erlyberly.node; + +import java.io.File; +import java.io.FileInputStream; + +import com.ericsson.otp.erlang.OtpInputStream; + +public class TraceFileReader extends OtpUtilTest { + + public static void main(String[] args) throws Exception { + byte[] bytes = new byte[1024 * 2]; + int read = 0; + FileInputStream fs = new FileInputStream(new File("/tmp/trace0nonode@nohost")); + try { + while (true) { + read = fs.read(bytes, 0, 1); + if (read == -1) + return; // eof + byte type = bytes[0]; + read = fs.read(bytes, 0, 4); + int size = decode(bytes); + read = fs.read(bytes, 0, size); + if(read != size) { + System.out.println("ERROR: size of message was less than was actually read, size: " + size + " read: " + read); + return; + } + System.out.println("TYPE: " + type + " SIZE: " + size); + OtpInputStream otpInputStream = new OtpInputStream(bytes, 0, size, 0); + System.out.println("TRACE TERMS " + otpInputStream.read_any()); + otpInputStream.close(); + } + } + finally { + fs.close(); + } + } + + private static int decode(byte[] bytes) { + return bytes[3] & 0xFF | (bytes[2] & 0xFF) << 8 | (bytes[1] & 0xFF) << 16 | (bytes[0] & 0xFF) << 24; + } +} diff --git a/src/main/java/erlyberly/node/TraceManager.java b/src/main/java/erlyberly/node/TraceManager.java index 521123e..92a1d7e 100644 --- a/src/main/java/erlyberly/node/TraceManager.java +++ b/src/main/java/erlyberly/node/TraceManager.java @@ -20,15 +20,15 @@ import java.util.ArrayList; import java.util.HashMap; import java.util.List; -import java.util.Map; import java.util.Stack; import com.ericsson.otp.erlang.OtpErlangAtom; import com.ericsson.otp.erlang.OtpErlangList; import com.ericsson.otp.erlang.OtpErlangObject; -import com.ericsson.otp.erlang.OtpErlangString; +import com.ericsson.otp.erlang.OtpErlangPid; import com.ericsson.otp.erlang.OtpErlangTuple; +import erlyberly.ErlyBerly; import erlyberly.TraceLog; public class TraceManager { @@ -39,8 +39,14 @@ public class TraceManager { private static final OtpErlangAtom CALL_ATOM = new OtpErlangAtom("call"); - private final HashMap> unfinishedCalls = new HashMap>(); + private final HashMap> unfinishedCalls = new HashMap>(); + /** + * Called when a trace log is received. + *
+ * Should only accessed from the FX thread. + */ + private RpcCallback traceLogCallback; public List collateTraces(OtpErlangList traceLogs) { final ArrayList traceList = new ArrayList(); @@ -60,53 +66,50 @@ public List collateTraceSingle(OtpErlangTuple traceLog) { private void decodeTraceLog(OtpErlangObject otpErlangObject, ArrayList traceList) { OtpErlangTuple tup = (OtpErlangTuple) otpErlangObject; - OtpErlangAtom traceType = (OtpErlangAtom) tup.elementAt(0); + OtpErlangAtom traceType = (OtpErlangAtom) tup.elementAt(2); if(CALL_ATOM.equals(traceType)) { TraceLog trace = proplistToTraceLog(tup); - Stack stack = unfinishedCalls.get(trace.getPidString()); + Stack stack = unfinishedCalls.get(trace.getPid()); if(stack == null) stack = new Stack(); stack.add(trace); - unfinishedCalls.put(trace.getPidString(), stack); + unfinishedCalls.put(trace.getPid(), stack); - traceList.add(trace); + if(traceLogCallback != null) + traceLogCallback.callback(trace); } else if(RETURN_FROM_ATOM.equals(traceType) || EXCEPTION_FROM_ATOM.equals(traceType)) { - Map map = propsFromTrace(tup); - - Object object = map.get(TraceLog.ATOM_PID); - - if(object != null) { - OtpErlangString pidString = (OtpErlangString) object; - - Stack stack = unfinishedCalls.get(pidString.stringValue()); - if(stack == null) - return; - - TraceLog traceLog = stack.pop(); - traceLog.complete(map); - - if(stack.isEmpty()) - unfinishedCalls.remove(pidString.stringValue()); - } - + assert tup.elementAt(1) instanceof OtpErlangPid; + OtpErlangPid tracedPid = (OtpErlangPid) tup.elementAt(1); + Stack stack = unfinishedCalls.get(tracedPid); + if(stack == null) + return; + TraceLog traceLog = stack.pop(); + traceLog.complete(tup, ErlyBerly.getTermFormatter()); + if(stack.isEmpty()) + unfinishedCalls.remove(tracedPid); + } + else { + assert false : traceType; } } private TraceLog proplistToTraceLog(OtpErlangTuple tup) { - Map map = propsFromTrace(tup); - - TraceLog trace = new TraceLog(map); + TraceLog trace = new TraceLog(tup, ErlyBerly.getTermFormatter()); return trace; } - private Map propsFromTrace(OtpErlangTuple tup) { - return OtpUtil.propsToMap((OtpErlangList) tup.elementAt(1)); + public RpcCallback getTraceLogCallback() { + return traceLogCallback; + } + + public void setTraceLogCallback(RpcCallback traceLogCallback) { + this.traceLogCallback = traceLogCallback; } } diff --git a/src/main/java/erlyberly/node/TraceServerConnection.java b/src/main/java/erlyberly/node/TraceServerConnection.java new file mode 100644 index 0000000..1e2d555 --- /dev/null +++ b/src/main/java/erlyberly/node/TraceServerConnection.java @@ -0,0 +1,93 @@ +package erlyberly.node; + +import java.io.BufferedInputStream; +import java.io.FileOutputStream; +import java.io.IOException; +import java.net.Socket; + +import com.ericsson.otp.erlang.OtpErlangObject; +import com.ericsson.otp.erlang.OtpErlangTuple; +import com.ericsson.otp.erlang.OtpInputStream; + +public class TraceServerConnection { + + private static final int DEFAULT_BUFFER_SIZE = 1024*10; + + private final TraceManager traceManager; + + private Socket socket; + private Thread thread; + private byte[] buffer; + + public TraceServerConnection(TraceManager aTraceManager) { + this.traceManager = aTraceManager; + } + + public void connect(String host, int port) throws IOException { + socket = new Socket(host, port); + thread = new Thread(this::run, "Tracer TCP Connection"); + thread.start(); + } + + private void run() { + BufferedInputStream inStream; + FileOutputStream outStream = null; + buffer = new byte[DEFAULT_BUFFER_SIZE]; + int read = 0; + try { + inStream = new BufferedInputStream(socket.getInputStream()); + outStream = new FileOutputStream("/tmp/erlyberlytrace"); + int offset = 0; + while(true) { + // offset in the byte array to write to + offset = 0; + // read the message type, read blocks but if the read size if less + // than 1 then just loop again, docs are a little unclear as to what + // circumstance it will ceast to block + read = inStream.read(buffer, offset++, 1); + if(read < 1) { + continue; + } + // read the size of the binary term + read = inStream.read(buffer, offset, 4); + // TODO better check read value is 4 + assert read == 4 : read; + // if the size of the message is greater than the buffer then + // permanently resize the buffer to the size of the message + int size = decodeIntFromBytes(buffer, offset); + offset += 4; + if(size > buffer.length) { + buffer = new byte[5+size]; + } + read = inStream.read(buffer, offset, size); + assert read == size : "read: " + read + " size: " + size; + OtpInputStream otpInputStream = new OtpInputStream(buffer, offset, size, 0); + OtpErlangObject traceTerm = otpInputStream.read_any(); + assert traceTerm instanceof OtpErlangTuple : traceTerm; + traceManager.collateTraceSingle((OtpErlangTuple) traceTerm); + otpInputStream.close(); + System.out.println(traceTerm); // TODO remove + outStream.write(buffer, 0, 5+size); + } + } + catch (Exception e) { + e.printStackTrace(); + } + finally { + safeCloseStream(outStream); + } + } + + private void safeCloseStream(FileOutputStream outStream) { + try { + outStream.close(); + } + catch (IOException e) { + e.printStackTrace(); + } + } + + private static int decodeIntFromBytes(byte[] bytes, int offset) { + return bytes[3+offset] & 0xFF | (bytes[2+offset] & 0xFF) << 8 | (bytes[1+offset] & 0xFF) << 16 | (bytes[0+offset] & 0xFF) << 24; + } +} diff --git a/src/main/resources/erlyberly/beam/erlyberly.erl b/src/main/resources/erlyberly/beam/erlyberly.erl index 8e499d7..7b9f498 100644 --- a/src/main/resources/erlyberly/beam/erlyberly.erl +++ b/src/main/resources/erlyberly/beam/erlyberly.erl @@ -19,7 +19,7 @@ -export([collect_seq_trace_logs/0]). -export([collect_trace_logs/0]). --export([ensure_dbg_started/2]). +-export([ensure_dbg_started/3]). -export([ensure_xref_started/0]). -export([saleyn_fun_src/1]). -export([get_abstract_code/1]). @@ -180,7 +180,6 @@ module_functions2(Mod) when is_atom(Mod) -> start_trace({Node, Pid}, Mod, Func, Arity, Max_queue_len) when is_atom(Node), is_pid(Pid), is_integer(Max_queue_len) -> - ensure_dbg_started({Node, Pid}, Max_queue_len), Ref = make_ref(), erlyberly_tcollector ! {start_trace, Mod, Func, Arity, self(), Ref}, receive @@ -210,7 +209,8 @@ when_process_is_unregistered(ProcName, Fn) -> _ -> ok end. %% -ensure_dbg_started({Eb_Node, Eb_pid}, Max_queue_len) -> +ensure_dbg_started({Eb_Node, Eb_pid}, Port, Max_queue_len) when is_integer(Port), + is_integer(Max_queue_len) -> % restart dbg when_process_is_unregistered(dbg, fun dbg:start/0), StartFn = @@ -219,12 +219,16 @@ ensure_dbg_started({Eb_Node, Eb_pid}, Max_queue_len) -> register(erlyberly_tcollector, Pid), % create a tracer that will send the trace logs to erlyberly_tcollector % to be stored. - TraceFn = - fun (Trace, _) -> - store_trace(Trace), - ok - end, - dbg:tracer(process, {TraceFn, ok}) + % TraceFn = + % fun (Trace, _) -> + % store_trace(Trace), + % ok + % end, + + %% this starts a TCP server on the port, which erlyberly connects into, + %% the max queue len is the limit at which the tracer starts to drop + %% messages if it is backed up + dbg:tracer(port, dbg:trace_port(ip, Port)) end, when_process_is_unregistered(erlyberly_tcollector, StartFn). @@ -504,9 +508,6 @@ collect_seq_trace_logs() -> %% ensure_seq_tracer_started(Remote_node) -> - %% TODO configure value for seq trace max queeu length - ensure_dbg_started(Remote_node, 500), - case whereis(?erlyberly_seq_trace) of undefined -> start_seq_tracer(Remote_node); From 61f634ad88b48981542baeb9af13301fc596351b Mon Sep 17 00:00:00 2001 From: andytill Date: Sun, 27 Aug 2017 10:43:22 +0000 Subject: [PATCH 02/10] Minor improvements, started to remove obsolete code from erlyberly.erl --- src/main/java/erlyberly/ErlyBerly.java | 12 +- src/main/java/erlyberly/TraceLog.java | 2 +- .../java/erlyberly/node/TraceFileReader.java | 2 +- .../erlyberly/node/TraceServerConnection.java | 2 +- .../resources/erlyberly/beam/erlyberly.erl | 366 +++++------------- 5 files changed, 119 insertions(+), 265 deletions(-) diff --git a/src/main/java/erlyberly/ErlyBerly.java b/src/main/java/erlyberly/ErlyBerly.java index f0374ea..69ec03d 100644 --- a/src/main/java/erlyberly/ErlyBerly.java +++ b/src/main/java/erlyberly/ErlyBerly.java @@ -77,7 +77,16 @@ public static void main(String[] args) throws Exception { } public static void runIO(Runnable runnable) { - IO_EXECUTOR.execute(runnable); + IO_EXECUTOR.execute(() -> { + try { + runnable.run(); + } + catch(Exception e) { + // print here or no console output is written at all + e.printStackTrace(); + throw e; + } + }); } public static void runIOAndWait(Runnable runnable) { @@ -87,6 +96,7 @@ public static void runIOAndWait(Runnable runnable) { } catch (Exception e) { e.printStackTrace(); + throw new RuntimeException(e); } } diff --git a/src/main/java/erlyberly/TraceLog.java b/src/main/java/erlyberly/TraceLog.java index de13ca8..14377b9 100644 --- a/src/main/java/erlyberly/TraceLog.java +++ b/src/main/java/erlyberly/TraceLog.java @@ -131,7 +131,7 @@ private long tupleToTimestamp(OtpErlangTuple tuple) { private long tupleElementToLong(int index, OtpErlangTuple tuple) { assert index < tuple.arity() : tuple; - assert tuple.elementAt(index) instanceof OtpErlangLong; + assert tuple.elementAt(index) instanceof OtpErlangLong : tuple; return ((OtpErlangLong)tuple.elementAt(index)).longValue(); } diff --git a/src/main/java/erlyberly/node/TraceFileReader.java b/src/main/java/erlyberly/node/TraceFileReader.java index fee27a8..aa34433 100644 --- a/src/main/java/erlyberly/node/TraceFileReader.java +++ b/src/main/java/erlyberly/node/TraceFileReader.java @@ -5,7 +5,7 @@ import com.ericsson.otp.erlang.OtpInputStream; -public class TraceFileReader extends OtpUtilTest { +public class TraceFileReader { public static void main(String[] args) throws Exception { byte[] bytes = new byte[1024 * 2]; diff --git a/src/main/java/erlyberly/node/TraceServerConnection.java b/src/main/java/erlyberly/node/TraceServerConnection.java index 1e2d555..ecd90b5 100644 --- a/src/main/java/erlyberly/node/TraceServerConnection.java +++ b/src/main/java/erlyberly/node/TraceServerConnection.java @@ -43,7 +43,7 @@ private void run() { offset = 0; // read the message type, read blocks but if the read size if less // than 1 then just loop again, docs are a little unclear as to what - // circumstance it will ceast to block + // circumstance it will cease to block read = inStream.read(buffer, offset++, 1); if(read < 1) { continue; diff --git a/src/main/resources/erlyberly/beam/erlyberly.erl b/src/main/resources/erlyberly/beam/erlyberly.erl index 7b9f498..3880d40 100644 --- a/src/main/resources/erlyberly/beam/erlyberly.erl +++ b/src/main/resources/erlyberly/beam/erlyberly.erl @@ -18,7 +18,6 @@ -module(erlyberly). -export([collect_seq_trace_logs/0]). --export([collect_trace_logs/0]). -export([ensure_dbg_started/3]). -export([ensure_xref_started/0]). -export([saleyn_fun_src/1]). @@ -34,9 +33,6 @@ -export([stop_traces/0]). -export([xref_analysis/4]). -%% exported for spawned processes --export([erlyberly_tcollector/3]). - %%% ============================================================================ %%% gen_event function exports %%% ============================================================================ @@ -83,9 +79,9 @@ process_info2([Proc | Tail], Acc) -> stack_size, total_heap_size]), Acc1 = case Props of - undefined -> + undefined -> Acc; - _ -> + _ -> Props1 = add_global_name(Proc, Props), Props2 = [{pid, pid_to_list(Proc)} | size_props_to_bytes(Props1)], [Props2 | Acc] @@ -211,257 +207,105 @@ when_process_is_unregistered(ProcName, Fn) -> %% ensure_dbg_started({Eb_Node, Eb_pid}, Port, Max_queue_len) when is_integer(Port), is_integer(Max_queue_len) -> - % restart dbg - when_process_is_unregistered(dbg, fun dbg:start/0), - StartFn = - fun() -> - Pid = proc_lib:spawn(?MODULE, erlyberly_tcollector, [Eb_Node, Eb_pid, Max_queue_len]), - register(erlyberly_tcollector, Pid), - % create a tracer that will send the trace logs to erlyberly_tcollector - % to be stored. - % TraceFn = - % fun (Trace, _) -> - % store_trace(Trace), - % ok - % end, - - %% this starts a TCP server on the port, which erlyberly connects into, - %% the max queue len is the limit at which the tracer starts to drop - %% messages if it is backed up - dbg:tracer(port, dbg:trace_port(ip, Port)) - end, - when_process_is_unregistered(erlyberly_tcollector, StartFn). - -%% -store_trace(Trace) -> - erlyberly_tcollector ! Trace. - --record(tcollector, { - ui_pid, - - %% - traces = [], - - %% the maximum message queue length that the collector can accrue before - %% tracing is suspended - max_queue_len -}). - -erlyberly_tcollector(Node, Pid, Max_queue_len) when is_integer(Max_queue_len) -> - % throws a badarg if the node has already closed down - erlang:monitor_node(Node, true), - - % apply a trace on the returns of the code module, so we can listen for - % code reloads, a code reload removes all traces on that module so when we - % receive this message, reapply all traces for that module + %% FIXME we still need a process to monitor the erlyberly node going down, + %% and stop dbg if it does. + ok = dbg:stop(), + {ok,_} = dbg:start(), + {ok,_} = dbg:tracer(port, dbg:trace_port(ip, {Port, Max_queue_len})), {ok,_} = dbg:p(all, [c, timestamp]), - {ok,_} = dbg:tp(code, x), - erlyberly_tcollector2(#tcollector{ ui_pid = Pid, - max_queue_len = Max_queue_len }). - -%% -erlyberly_tcollector2(#tcollector{ ui_pid = UI_pid, max_queue_len = Max_queue_len } = TC) -> - case process_info(self(), message_queue_len) of - {message_queue_len, Queue_len} when Queue_len > Max_queue_len -> - %% io:format("~nSTOPPING TRACING, Queue Len: ~p, Max Len: ~p~n", [Queue_len, Max_queue_len]), - ok = dbg:stop_clear(), - UI_pid ! {erlyberly_trace_overload, Queue_len}, - collect_overloading_logs(Max_queue_len, TC); - _ -> - receive_next_trace(TC) - end. - -%% Collect logs that in the message queue, even though we have suspended -%% tracing. This is to try and show what was causing the overload. -collect_overloading_logs(0, _) -> - ok; -collect_overloading_logs(Max_queue_len, TC) -> - receive - Log -> - case collect_log(Log) of - skip -> - collect_overloading_logs(Max_queue_len-1, TC); - {erlyberly_module_loaded, _} -> - collect_overloading_logs(Max_queue_len-1, TC); - Trace_log -> - notify_erlyberly_trace_log(Trace_log, TC), - collect_overloading_logs(Max_queue_len-1, TC) - end - after - 0 -> ok - end. + {ok,_} = dbg:tp({code, ensure_loaded, 1}, c), + ok. -receive_next_trace(#tcollector{ traces = Traces } = TC) -> - receive - {start_trace, Mod, Func, Arity, Requester, Ref} when is_pid(Requester), - is_reference(Ref) -> - TC1 = tcollector_start_trace(Mod, Func, Arity, TC), - Requester ! {ok, Ref}, - erlyberly_tcollector2(TC1); - {stop_trace, Mod, Func, Arity} -> - dbg:ctpl(Mod, Func, Arity), - Traces_1 = Traces -- [{Mod, Func, Arity}], - TC1 = TC#tcollector{ traces = Traces_1 }, - erlyberly_tcollector2(TC1); - stop_traces -> - ok = dbg:stop_clear(); - {nodedown, _Node} -> - ok = dbg:stop_clear(); - Log -> - case collect_log(Log) of - skip -> - ok; - {erlyberly_module_loaded, Loaded_module} -> - ok = reapply_traces(Loaded_module, TC#tcollector.traces), - ok = notify_erlyberly_module_loaded(Loaded_module, TC); - Trace_log -> - notify_erlyberly_trace_log(Trace_log, TC) - end, - erlyberly_tcollector2(TC) - end. +% receive_next_trace(#tcollector{ traces = Traces } = TC) -> +% receive +% {start_trace, Mod, Func, Arity, Requester, Ref} when is_pid(Requester), +% is_reference(Ref) -> +% TC1 = tcollector_start_trace(Mod, Func, Arity, TC), +% Requester ! {ok, Ref}, +% erlyberly_tcollector2(TC1); +% {stop_trace, Mod, Func, Arity} -> +% dbg:ctpl(Mod, Func, Arity), +% Traces_1 = Traces -- [{Mod, Func, Arity}], +% TC1 = TC#tcollector{ traces = Traces_1 }, +% erlyberly_tcollector2(TC1); +% stop_traces -> +% ok = dbg:stop_clear(); +% {nodedown, _Node} -> +% ok = dbg:stop_clear(); +% Log -> +% case collect_log(Log) of +% skip -> +% ok; +% {erlyberly_module_loaded, Loaded_module} -> +% ok = reapply_traces(Loaded_module, TC#tcollector.traces), +% ok = notify_erlyberly_module_loaded(Loaded_module, TC); +% Trace_log -> +% notify_erlyberly_trace_log(Trace_log, TC) +% end, +% erlyberly_tcollector2(TC) +% end. + +% %% +% tcollector_start_trace(Mod, Func, Arity, #tcollector{ traces = Traces } = TC) -> +% Match_spec = [{'_', [], [{message,{process_dump}}, {exception_trace}]}], +% Trace_spec = {Mod, Func, Arity}, +% dbg:tpl(Trace_spec, Match_spec), +% dbg:p(all, [c, timestamp]), +% TC#tcollector{ traces = [Trace_spec | Traces] }. %% -tcollector_start_trace(Mod, Func, Arity, #tcollector{ traces = Traces } = TC) -> - Match_spec = [{'_', [], [{message,{process_dump}}, {exception_trace}]}], - Trace_spec = {Mod, Func, Arity}, - dbg:tpl(Trace_spec, Match_spec), - dbg:p(all, [c, timestamp]), - TC#tcollector{ traces = [Trace_spec | Traces] }. +% collect_log({trace_ts, _, return_from, {code, ensure_loaded, _}, _}) -> +% % ensure loaded can be called many times for one reload so just skip it +% skip; +% collect_log({trace_ts, _, return_from, {code, _, _}, {module, Loaded_module}, _}) -> +% % if we trace that a module is reloaded then reapply traces to it +% %ok = reapply_traces(Loaded_module, TC#tcollector.traces), +% %ok = notify_erlyberly_module_loaded(Loaded_module, TC), +% {erlyberly_module_loaded, Loaded_module}; +% collect_log({trace_ts, _, _, {code, _, _}, _}) -> +% skip; +% collect_log({trace_ts, _, _, {code, _, _}}) -> +% skip; +% collect_log(Trace) when element(1, Trace) == trace_ts orelse element(1, Trace) == trace -> +% trace_to_props(Trace); +% collect_log(U) -> +% io:format("unknown trace ~p~n", [U]), +% skip. + +% notify_erlyberly_module_loaded(Loaded_module, #tcollector{ ui_pid = Pid }) -> +% Pid ! {erlyberly_module_loaded, Loaded_module, module_functions2(Loaded_module)}, +% ok. + +% notify_erlyberly_trace_log(Trace_log, #tcollector{ ui_pid = Pid }) -> +% Pid ! {erlyberly_trace_log, Trace_log}, +% ok. %% -collect_log({trace_ts, _, return_from, {code, ensure_loaded, _}, _}) -> - % ensure loaded can be called many times for one reload so just skip it - skip; -collect_log({trace_ts, _, return_from, {code, _, _}, {module, Loaded_module}, _}) -> - % if we trace that a module is reloaded then reapply traces to it - %ok = reapply_traces(Loaded_module, TC#tcollector.traces), - %ok = notify_erlyberly_module_loaded(Loaded_module, TC), - {erlyberly_module_loaded, Loaded_module}; -collect_log({trace_ts, _, _, {code, _, _}, _}) -> - skip; -collect_log({trace_ts, _, _, {code, _, _}}) -> - skip; -collect_log(Trace) when element(1, Trace) == trace_ts orelse element(1, Trace) == trace -> - trace_to_props(Trace); -collect_log(U) -> - io:format("unknown trace ~p~n", [U]), - skip. - -notify_erlyberly_module_loaded(Loaded_module, #tcollector{ ui_pid = Pid }) -> - Pid ! {erlyberly_module_loaded, Loaded_module, module_functions2(Loaded_module)}, - ok. - -notify_erlyberly_trace_log(Trace_log, #tcollector{ ui_pid = Pid }) -> - Pid ! {erlyberly_trace_log, Trace_log}, - ok. +% reapply_traces(Loaded_module, Traces) -> +% % filter out the traces for the reloaded, module, could be +% % done in the list comp but it causes a compiler warning +% Traces_1 = lists:filter(fun(T) -> +% element(1, T) == Loaded_module +% end, Traces), -%% Convert a 'call' trace (a normal function call, before return) to a -%% {call, proplists()} that erlyberly can understand. -call_trace_props(Pid, Func, Timestamp, Extra_props) -> - {call, - [ {pid, pid_to_list(Pid)}, - {reg_name, get_registered_name(Pid)}, - {fn, Func}, - {timetamp_call_us, timestamp_to_us(Timestamp)} | Extra_props ]}. - -%% Covert a 'return_from' trace into proplists erlyberly can understand -return_from_trace_props(Pid, Result, Timestamp) -> - {return_from, - [ {pid, pid_to_list(Pid)}, - {reg_name, get_registered_name(Pid)}, - {result, Result}, - {timetamp_return_us, timestamp_to_us(Timestamp)} ]}. - -%% -trace_to_props({trace_ts, Pid, call, {Mod, Func_name, [Req, State]}, _, Timestamp}) when Func_name == handle_info orelse - Func_name == handle_cast -> - call_trace_props(Pid, {Mod, Func_name, [Req, format_record(State, Mod)]}, Timestamp, []); -trace_to_props({trace_ts, Pid, call, {Mod, handle_call, [Req, From, State]}, _, Timestamp}) -> - call_trace_props(Pid, {Mod, handle_call, [Req, From, format_record(State, Mod)]}, Timestamp, []); -trace_to_props({trace_ts, Pid, call, Func, Msg, Timestamp}) -> - Stack_trace = - try - [{stack_trace, stak(Msg)}] - catch - _C:_Error -> - % io:format("ERROR ~p~n", [_Error]) - [] - end, - % call handler for everything else - call_trace_props(Pid, Func, Timestamp, Stack_trace); -trace_to_props({trace_ts, Pid, return_from, {Mod, Func_name, _}, {noreply, Rec}, Timestamp}) when Func_name == handle_info orelse - Func_name == handle_cast orelse - Func_name == handle_call -> - return_from_trace_props(Pid, {noreply, format_record(Rec, Mod)}, Timestamp); - -trace_to_props({trace_ts, Pid, return_from, {Mod, handle_call, _}, {reply, Reply, Rec}, Timestamp}) -> - return_from_trace_props(Pid, {reply, Reply, format_record(Rec, Mod)}, Timestamp); -trace_to_props({trace_ts, Pid, return_from, _Func, Result, Timestamp}) -> - % return from handler for everything else - return_from_trace_props(Pid, Result, Timestamp); -trace_to_props({trace_ts, Pid, exception_from, Func, {Class, Value}, Timestamp}) -> - {exception_from, - [ {pid, pid_to_list(Pid)}, - {reg_name, get_registered_name(Pid)}, - {fn, Func}, - {exception_from, {Class, Value}}, - {timetamp_return_us, timestamp_to_us(Timestamp)} ]}; -trace_to_props({trace, Pid, call, Func, _}) -> - {call, - [ {pid, pid_to_list(Pid)}, - {reg_name, get_registered_name(Pid)}, - {fn, Func} ]}; -trace_to_props({trace, Pid, exception_from, Func, {Class, Value}}) -> - {exception_from, - [ {pid, pid_to_list(Pid)}, - {reg_name, get_registered_name(Pid)}, - {fn, Func}, - {exception_from, {Class, Value}} ]}; -trace_to_props({trace, Pid, return_from, Func, Result}) -> - {return_from, - [ {pid, pid_to_list(Pid)}, - {reg_name, get_registered_name(Pid)}, - {fn, Func}, - {result, Result} ]}; -trace_to_props(U) -> - io:format("skipped trace_ts ~p~n", [U]), - skip. +% % reapply each trace that has the loaded module +% [erlyberly_tcollector ! {start_trace, M, F, A, self(), make_ref()} || {M, F, A} <- Traces_1], +% ok. %% -reapply_traces(Loaded_module, Traces) -> - % filter out the traces for the reloaded, module, could be - % done in the list comp but it causes a compiler warning - Traces_1 = lists:filter(fun(T) -> - element(1, T) == Loaded_module - end, Traces), - - % reapply each trace that has the loaded module - [erlyberly_tcollector ! {start_trace, M, F, A, self(), make_ref()} || {M, F, A} <- Traces_1], - ok. -%% -collect_trace_logs() -> - case whereis(erlyberly_tcollector) of - undefined -> - % monitoring of a pid from jinterface is not implemented as far as I can - % tell so just make do with polling - {error, tcollector_down}; - _ -> - erlyberly_tcollector ! {take_logs, self()}, - receive - {trace_logs, Logs} -> {ok, Logs} - after 2000 -> {error, tcollector_timeout} - end - end. -%% -get_registered_name(Pid) -> - case erlang:process_info(Pid, registered_name) of - [{_, Name}] -> Name; - {_, Name} -> Name; - _ -> undefined - end. - -timestamp_to_us({Mega, Sec, Micros}) -> - (((Mega * 1000000) + Sec) * 1000000) + Micros. +% collect_trace_logs() -> +% case whereis(erlyberly_tcollector) of +% undefined -> +% % monitoring of a pid from jinterface is not implemented as far as I can +% % tell so just make do with polling +% {error, tcollector_down}; +% _ -> +% erlyberly_tcollector ! {take_logs, self()}, +% receive +% {trace_logs, Logs} -> {ok, Logs} +% after 2000 -> {error, tcollector_timeout} +% end +% end. %%% ============================================================================= %%% @@ -499,7 +343,7 @@ collect_seq_trace_logs() -> _ -> ?erlyberly_seq_trace ! {take_seq_logs, self()}, receive - {seq_trace_logs, Logs} -> + {seq_trace_logs, Logs} -> {ok, Logs} after 2000 -> {error, timeout} @@ -517,7 +361,7 @@ ensure_seq_tracer_started(Remote_node) -> %% start_seq_tracer({Node, _}) -> - Tracer_collector_pid = + Tracer_collector_pid = proc_lib:spawn( fun() -> % throws a badarg if the node has already closed down @@ -575,14 +419,14 @@ format_pid(Port) when is_port(Port) -> %% format_utc_timestamp() -> TS = {_,_,Micro} = os:timestamp(), - {{Year,Month,Day},{Hour,Minute,Second}} = + {{Year,Month,Day},{Hour,Minute,Second}} = calendar:now_to_universal_time(TS), Mstr = element(Month,{"Jan","Feb","Mar","Apr","May","Jun","Jul", "Aug","Sep","Oct","Nov","Dec"}), io_lib:format("~2w ~s ~4w ~2w:~2..0w:~2..0w.~6..0w", [Day,Mstr,Year,Hour,Minute,Second,Micro]). --define(SET_SEQ_TOKEN, +-define(SET_SEQ_TOKEN, set_seq_token(send, true), set_seq_token('receive', true), set_seq_token(timestamp, true), @@ -731,14 +575,14 @@ get_abstract_code(What) -> end. mod_src(Module) -> - abstract_code(Module, fun(Forms) -> + abstract_code(Module, fun(Forms) -> {ok, list_to_binary( lists:flatten([[erl_pp:form(F),$\n] || F <- Forms, element(1,F) =:= attribute orelse element(1,F) =:= function]) )} end). - + fun_src(Mod, Fun, Arity) -> - abstract_code(Mod, fun(Forms) -> + abstract_code(Mod, fun(Forms) -> [FF] = [FF || FF = {function, _Line, Fun2, Arity2, _} <- Forms, Fun2 =:= Fun, Arity2 =:= Arity], {ok, list_to_binary( lists:flatten(erl_pp:form(FF)) @@ -746,14 +590,14 @@ fun_src(Mod, Fun, Arity) -> end). mod_abst(Module) -> - abstract_code(Module, fun(Forms) -> + abstract_code(Module, fun(Forms) -> {ok, list_to_binary( lists:flatten(io_lib:format("~p", [Forms])) )} end). fun_abst(Mod, Fun, Arity) -> - abstract_code(Mod, fun(Forms) -> + abstract_code(Mod, fun(Forms) -> [FF] = [FF || FF = {function, _Line, Fun2, Arity2, _} <- Forms, Fun2 =:= Fun, Arity2 =:= Arity], {ok, list_to_binary( lists:flatten(io_lib:format("~p", [FF])) @@ -762,7 +606,7 @@ fun_abst(Mod, Fun, Arity) -> abstract_code(Module, ExecFun) -> File = code:which(Module), - case beam_lib:chunks(File, [abstract_code]) of + case beam_lib:chunks(File, [abstract_code]) of {ok,{_Mod,[{abstract_code,no_abstract_code}]}} -> {ok,"no_abstract_code for Module "+atom_to_list(Module)+"."}; {ok,{_Mod,[{abstract_code,{_Version,Forms}}]}} -> @@ -786,7 +630,7 @@ handle_event({error_report,_,{_, crash_report, Crash_props_1}}, State) -> Node ! {erlyberly_error_report, lists:flatten(Crash_props_1)}, {ok, State}; handle_event(_, State) -> - % io:format("error: ~p ~p~n", [element(1,E), tuple_size(E) ]), + % io:format("error: ~p ~p~n", [element(1,E), tuple_size(E) ]), {ok, State}. @@ -805,14 +649,14 @@ code_change(_OldVsn, State, _Extra) -> {ok, State}. %%% https://github.com/massemanet/eper/blob/f7a1b4504f5eefc61fb9da7101fdaccc687021cd/src/redbug.erl %%% %%% Copyright (c) 2008-2013 mats cronqvist -%%% +%%% %%% Permission is hereby granted, free of charge, to any person obtaining a copy %%% of this software and associated documentation files (the "Software"), to deal %%% in the Software without restriction, including without limitation the rights %%% to use, copy, modify, merge, publish, distribute, sublicense, and/or sell %%% copies of the Software, and to permit persons to whom the Software is %%% furnished to do so, subject to the following conditions: -%%% +%%% %%% The above copyright notice and this permission notice shall be included in %%% all copies or substantial portions of the Software. From c059757200111a166360eddcb7dfcf1b1f82c871 Mon Sep 17 00:00:00 2001 From: andytill Date: Mon, 4 Sep 2017 10:59:52 +0000 Subject: [PATCH 03/10] Get code reloading into erlyberly working again. --- src/main/java/erlyberly/ConnectionView.java | 2 +- src/main/java/erlyberly/DbgController.java | 34 ++----- src/main/java/erlyberly/TraceList.java | 35 ++++++++ src/main/java/erlyberly/TraceLog.java | 6 +- src/main/java/erlyberly/node/NodeAPI.java | 89 +++++++++++++++---- src/main/java/erlyberly/node/OtpUtil.java | 9 ++ .../java/erlyberly/node/TraceManager.java | 68 +++++++++++++- .../erlyberly/node/TraceServerConnection.java | 5 +- .../resources/erlyberly/beam/erlyberly.erl | 43 +++++---- 9 files changed, 225 insertions(+), 66 deletions(-) create mode 100644 src/main/java/erlyberly/TraceList.java diff --git a/src/main/java/erlyberly/ConnectionView.java b/src/main/java/erlyberly/ConnectionView.java index 723098a..48fdd10 100644 --- a/src/main/java/erlyberly/ConnectionView.java +++ b/src/main/java/erlyberly/ConnectionView.java @@ -98,7 +98,7 @@ public void onConnect() { Platform.runLater(() -> { closeThisWindow(); }); } catch (OtpErlangException | OtpAuthException | IOException e) { - e.printStackTrace(); + // e.printStackTrace(); Platform.runLater(() -> { connectionFailed(e.getMessage()); }); } }); diff --git a/src/main/java/erlyberly/DbgController.java b/src/main/java/erlyberly/DbgController.java index 453fee9..5c1701d 100644 --- a/src/main/java/erlyberly/DbgController.java +++ b/src/main/java/erlyberly/DbgController.java @@ -19,7 +19,6 @@ import java.io.IOException; import java.net.URL; -import java.util.ArrayList; import java.util.List; import java.util.ResourceBundle; @@ -54,8 +53,6 @@ public class DbgController implements Initializable { private final ObservableList traceLogs = FXCollections.observableArrayList(); - private final ObservableList traces = FXCollections.observableArrayList(); - private final ObservableList seqTraces = FXCollections.observableArrayList(); private volatile boolean collectingSeqTraces; @@ -101,16 +98,12 @@ public ObservableList getSeqTraceLogs() { return seqTraces; } - public boolean isTraced(ModFunc function) { - return traces.contains(function); - } - public void toggleTraceModFunc(ModFunc function) { // if tracing is suspended, we can't apply a new trace because that will // leave us in a state where some traces are active and others are not if(ErlyBerly.nodeAPI().isSuspended()) return; - if(traces.contains(function)) + if(ErlyBerly.nodeAPI().isTraced(function)) onRemoveTracer(null, function); else traceModFunc(function); @@ -120,8 +113,6 @@ private void traceModFunc(ModFunc function) { ErlyBerly.runIO(() -> { try { ErlyBerly.nodeAPI().startTrace(function, PrefBind.getMaxTraceQueueLengthConfig()); - - Platform.runLater(() -> { traces.add(function); }); } catch (Exception ex) { ex.printStackTrace(); @@ -133,8 +124,6 @@ private void onRemoveTracer(ActionEvent e, ModFunc function) { ErlyBerly.runIO(() -> { try { ErlyBerly.nodeAPI().stopTrace(function); - - Platform.runLater(() -> { traces.remove(function); }); } catch (Exception ex) { ex.printStackTrace(); @@ -143,23 +132,13 @@ private void onRemoveTracer(ActionEvent e, ModFunc function) { } public void reapplyTraces() { - final int maxTraceQueueLengthConfig = PrefBind.getMaxTraceQueueLengthConfig(); - final ArrayList tracesCopy = new ArrayList(traces); ErlyBerly.runIO(() -> { - for (ModFunc function : tracesCopy) { - try { - ErlyBerly.nodeAPI().startTrace(function, maxTraceQueueLengthConfig); - } - catch (Exception e) { - e.printStackTrace(); - Platform.runLater(() -> { traces.remove(function); }); - } - } + erlyberly.ErlyBerly.nodeAPI().reapplyTraces(); }); } public void addTraceListener(InvalidationListener listener) { - traces.addListener(listener); + ErlyBerly.nodeAPI().addTraceListener(listener); } public void requestModFuncs(RpcCallback rpcCallback) { @@ -223,7 +202,7 @@ public GetModulesThread(RpcCallback anRpcCallback) { @Override public void run() { try { - OtpErlangList functions = ErlyBerly.nodeAPI().requestFunctions(); + OtpErlangList functions = ErlyBerly.nodeAPI().allModuleFunctions(); Platform.runLater(() -> { rpcCallback.callback(functions); }); } catch (Exception e) { @@ -235,6 +214,7 @@ public void run() { public String moduleFunctionSourceCode(String module, String function, Integer arity) throws IOException, OtpErlangException { return ErlyBerly.nodeAPI().moduleFunctionSourceCode(module, function, arity); } + public String moduleFunctionSourceCode(String module) throws IOException, OtpErlangException { return ErlyBerly.nodeAPI().moduleFunctionSourceCode(module); } @@ -243,6 +223,7 @@ public String moduleFunctionAbstCode(String module) throws IOException, OtpErlan String moduleCode = ErlyBerly.nodeAPI().moduleFunctionAbstractCode(module); return moduleCode; } + public String moduleFunctionAbstCode(String module, String function, Integer arity) throws IOException, OtpErlangException { String moduleCode = ErlyBerly.nodeAPI().moduleFunctionAbstractCode(module, function, arity); return moduleCode; @@ -252,4 +233,7 @@ public void setModuleLoadedCallback(RpcCallback moduleLoadedCall ErlyBerly.nodeAPI().setModuleLoadedCallback(moduleLoadedCallback); } + public boolean isTraced(ModFunc function) { + return ErlyBerly.nodeAPI().isTraced(function); + } } diff --git a/src/main/java/erlyberly/TraceList.java b/src/main/java/erlyberly/TraceList.java new file mode 100644 index 0000000..92f3663 --- /dev/null +++ b/src/main/java/erlyberly/TraceList.java @@ -0,0 +1,35 @@ +package erlyberly; + +import java.util.ArrayList; +import java.util.List; + +import javafx.beans.InvalidationListener; +import javafx.collections.FXCollections; +import javafx.collections.ObservableList; + +/** + * A list of erlang traces. + */ +public class TraceList { + private final ObservableList traces = FXCollections.observableArrayList(); + + public boolean isTraces(ModFunc function) { + return traces.contains(function); + } + + public void remove(ModFunc mf) { + traces.remove(mf); + } + + public void add(ModFunc mf) { + traces.add(mf); + } + + public List coptToList() { + return new ArrayList(traces); + } + + public void addListener(InvalidationListener listener) { + traces.addListener(listener); + } +} diff --git a/src/main/java/erlyberly/TraceLog.java b/src/main/java/erlyberly/TraceLog.java index 14377b9..73414d5 100644 --- a/src/main/java/erlyberly/TraceLog.java +++ b/src/main/java/erlyberly/TraceLog.java @@ -110,11 +110,11 @@ public TraceLog(OtpErlangTuple tuple, TermFormatter formatter) { ((OtpErlangAtom)mfa.elementAt(0)).atomValue(), ((OtpErlangAtom)mfa.elementAt(1)).atomValue(), arity, false, false); // the three element tuple timestamp - assert tuple.elementAt(4) instanceof OtpErlangTuple : "TRACE WAS " + tuple + " timestamp was " + formatter.toString(tuple.elementAt(4)); - callTime = tupleToTimestamp((OtpErlangTuple) tuple.elementAt(4)); + int timestampIndex = tuple.arity()-1; + assert tuple.elementAt(timestampIndex) instanceof OtpErlangTuple : "TRACE WAS " + tuple + " timestamp was " + formatter.toString(tuple.elementAt(timestampIndex)); + callTime = tupleToTimestamp((OtpErlangTuple) tuple.elementAt(timestampIndex)); functionString = formatter.modFuncArityToString( modFunc.getModuleName(), modFunc.getFuncName(), modFunc.getArity()); - } /** diff --git a/src/main/java/erlyberly/node/NodeAPI.java b/src/main/java/erlyberly/node/NodeAPI.java index e3421c5..51041a4 100644 --- a/src/main/java/erlyberly/node/NodeAPI.java +++ b/src/main/java/erlyberly/node/NodeAPI.java @@ -18,6 +18,7 @@ package erlyberly.node; import static erlyberly.node.OtpUtil.atom; +import static erlyberly.node.OtpUtil.element; import static erlyberly.node.OtpUtil.isTupleTagged; import static erlyberly.node.OtpUtil.list; import static erlyberly.node.OtpUtil.tuple; @@ -27,10 +28,13 @@ import java.time.LocalDateTime; import java.util.ArrayList; import java.util.Arrays; +import java.util.Collections; +import java.util.HashSet; import java.util.List; import java.util.Map; import java.util.Objects; import java.util.Random; +import java.util.Set; import java.util.concurrent.atomic.AtomicLong; import com.ericsson.otp.erlang.OtpAuthException; @@ -56,8 +60,10 @@ import erlyberly.PrefBind; import erlyberly.ProcInfo; import erlyberly.SeqTraceLog; +import erlyberly.TraceList; import erlyberly.TraceLog; import javafx.application.Platform; +import javafx.beans.InvalidationListener; import javafx.beans.Observable; import javafx.beans.property.SimpleBooleanProperty; import javafx.beans.property.SimpleObjectProperty; @@ -79,8 +85,6 @@ public class NodeAPI { private static final OtpErlangAtom ERLYBERLY_ERROR_REPORT_ATOM = atom("erlyberly_error_report"); - private static final OtpErlangAtom ERLYBERLY_MODULE_RELOADED_ATOM = atom("erlyberly_module_loaded"); - private static final OtpErlangAtom ERLYBERLY_ATOM = new OtpErlangAtom(ERLYBERLY); private static final OtpErlangAtom REX_ATOM = atom("rex"); @@ -123,8 +127,7 @@ public class NodeAPI { private boolean manuallyDisconnected = false; - private RpcCallback moduleLoadedCallback; - + private final TraceList traceList; /** * When tracing is paused, NodeAPI will stop all traces. When tracing is un-suspended * the DbgController must reapply all the traces. @@ -133,6 +136,9 @@ public class NodeAPI { private TraceServerConnection traceServerConnection; + + private final Set knownModules = Collections.synchronizedSet(new HashSet<>()); + public NodeAPI() { traceManager = new TraceManager(); @@ -155,6 +161,8 @@ public void changed(ObservableValue obv, Boolean o, Boolean n suspendedProperty = new SimpleBooleanProperty(); + traceList = new TraceList(); + try { String ourNodeName = "erlyberly" + new Random().nextInt(9999); self = new OtpSelfNode(ourNodeName); @@ -260,6 +268,7 @@ public void disconnect() { Platform.runLater(() -> { suspendedProperty.set(false); }); + knownModules.clear(); } private synchronized void ensureDbgStarted() throws IOException, OtpErlangException { @@ -341,12 +350,6 @@ private OtpErlangObject receiveRPC(OtpErlangObject receive) else if(isTupleTagged(ERLYBERLY_ERROR_REPORT_ATOM, tupleResult)) { Platform.runLater(() -> { crashReports.add(tupleResult.elementAt(1)); }); } - else if(isTupleTagged(ERLYBERLY_MODULE_RELOADED_ATOM, tupleResult)) { - Platform.runLater(() -> { - if(moduleLoadedCallback != null) - moduleLoadedCallback.callback((OtpErlangTuple) tupleResult.elementAt(2)); - }); - } else if(isTupleTagged(ERLYBERLY_TRACE_OVERLOAD_ATOM, tupleResult)) { Platform.runLater(() -> { suspendedProperty.set(true); }); } @@ -493,20 +496,44 @@ private void mySleep(int millis) { } } - public synchronized OtpErlangList requestFunctions() throws Exception { + /** + * Returns [{my_module, [{exported_func,3}], [{unexported_func,2}]}]. + */ + public synchronized OtpErlangList allModuleFunctions() throws Exception { assert !Platform.isFxApplicationThread() : CANNOT_RUN_THIS_METHOD_FROM_THE_FX_THREAD; - OtpErlangObject rpcResult = nodeRPC().blockingRPC(ERLYBERLY_ATOM, atom("module_functions"), list()); + OtpErlangObject rpcResult = nodeRPC().blockingRPC(ERLYBERLY_ATOM, atom("all_module_functions"), list()); if(rpcResult == null || !(rpcResult instanceof OtpErlangList)) { throw new RuntimeException("Result of module_functions call should be a list but got " + rpcResult); } - return (OtpErlangList) rpcResult; + OtpErlangList result = (OtpErlangList) rpcResult; + for (OtpErlangObject elem : result) { + knownModules.add((OtpErlangAtom) element(0, elem)); + } + return result; + } + + /** + * Returns {my_module, [{exported_func,3}], [{unexported_func,2}]}. + */ + public synchronized OtpErlangTuple moduleFunctions(OtpErlangAtom moduleName) throws Exception { + assert !Platform.isFxApplicationThread() : CANNOT_RUN_THIS_METHOD_FROM_THE_FX_THREAD; + OtpErlangObject rpcResult = nodeRPC().blockingRPC(ERLYBERLY_ATOM, atom("module_functions"), list(moduleName)); + assert isSuccessTerm(rpcResult) : rpcResult; + assert element(1, rpcResult) instanceof OtpErlangTuple : element(1, rpcResult); + return (OtpErlangTuple) element(1, rpcResult); } public synchronized void startTrace(ModFunc mf, int maxQueueLen) throws Exception { + // add the trace to the traced list to begin with + Platform.runLater(() -> { traceList.add(mf); }); assert !Platform.isFxApplicationThread() : CANNOT_RUN_THIS_METHOD_FROM_THE_FX_THREAD; assert mf.getFuncName() != null : "function name cannot be null"; - OtpErlangObject rpcResult = nodeRPC() - .blockingRPC(ERLYBERLY_ATOM, atom("start_trace"), toStartTraceFnArgs(mf, maxQueueLen)); + OtpErlangObject rpcResult = nodeRPC().blockingRPC(ERLYBERLY_ATOM, atom("start_trace"), + toStartTraceFnArgs(mf, maxQueueLen)); + // remove the trace if the rpc failed + if(!isSuccessTerm(rpcResult)) { + Platform.runLater(() -> { traceList.remove(mf); }); + } assert isSuccessTerm(rpcResult) : rpcResult; } @@ -521,6 +548,7 @@ public synchronized void stopTrace(ModFunc mf) throws Exception { mf.getArity(), mf.getArity() )); + Platform.runLater(() -> { traceList.remove(mf); }); assert isSuccessTerm(rpcResult) : rpcResult; // FIXME return the result for errors } @@ -733,7 +761,7 @@ public synchronized OtpErlangList dictToPropslist(OtpErlangObject dict) throws I * format {atom(), integer()}. */ public void setModuleLoadedCallback(RpcCallback aModuleLoadedCallback) { - moduleLoadedCallback = aModuleLoadedCallback; + traceManager.setModuleLoadedCallback(aModuleLoadedCallback); } public synchronized String decompileFun(OtpErlangFun fun) throws IOException, OtpErlangException { @@ -754,9 +782,13 @@ public void loadModule(OtpErlangAtom moduleNameAtom) throws OtpErlangException, assert moduleNameAtom != null : "module name string is null"; assert !"".equals(moduleNameAtom) : " module name string is empty"; assert !Platform.isFxApplicationThread() : CANNOT_RUN_THIS_METHOD_FROM_THE_FX_THREAD; + // if we already know about this module then there is no to load it again + if(knownModules.contains(moduleNameAtom)) + return; OtpErlangObject result = nodeRPC() .blockingRPC(atom("code"), atom("ensure_loaded"), list(moduleNameAtom)); assert isTupleTagged(atom("module"), result) || isTupleTagged(atom("error"), result) : result; + knownModules.add(moduleNameAtom); } public RpcCallback getTraceLogCallback() { @@ -791,4 +823,29 @@ public SimpleBooleanProperty suspendedProperty() { assert Platform.isFxApplicationThread(); return suspendedProperty; } + + public boolean isTraced(ModFunc function) { + return traceList.isTraces(function); + } + + public void reapplyTraces() { + final int maxTraceQueueLengthConfig = PrefBind.getMaxTraceQueueLengthConfig(); + for (ModFunc function : traceList.coptToList()) { + try { + ErlyBerly.nodeAPI().startTrace(function, maxTraceQueueLengthConfig); + } + catch (Exception e) { + e.printStackTrace(); + } + } + } + + /** + * Add a listener to the list of traces on functions. + * + * NOT on the trace logs. + */ + public void addTraceListener(InvalidationListener listener) { + traceList.addListener(listener); + } } diff --git a/src/main/java/erlyberly/node/OtpUtil.java b/src/main/java/erlyberly/node/OtpUtil.java index 5bbe5a1..e832005 100644 --- a/src/main/java/erlyberly/node/OtpUtil.java +++ b/src/main/java/erlyberly/node/OtpUtil.java @@ -277,4 +277,13 @@ public static OtpErlangTuple toTuple(OtpErlangObject obj) { } return (OtpErlangTuple) obj; } + + public static OtpErlangObject element(int index, OtpErlangObject term) { + if(term instanceof OtpErlangTuple) { + return ((OtpErlangTuple)term).elementAt(index); + } + else { + throw new RuntimeException(term.toString()); + } + } } diff --git a/src/main/java/erlyberly/node/TraceManager.java b/src/main/java/erlyberly/node/TraceManager.java index 92a1d7e..1aa5031 100644 --- a/src/main/java/erlyberly/node/TraceManager.java +++ b/src/main/java/erlyberly/node/TraceManager.java @@ -17,6 +17,8 @@ */ package erlyberly.node; +import static erlyberly.node.OtpUtil.atom; + import java.util.ArrayList; import java.util.HashMap; import java.util.List; @@ -30,10 +32,15 @@ import erlyberly.ErlyBerly; import erlyberly.TraceLog; +import javafx.application.Platform; public class TraceManager { - private static final OtpErlangAtom RETURN_FROM_ATOM = new OtpErlangAtom("return_from"); + private static final OtpErlangAtom MODULE_ATOM = atom("module"); + + private static final OtpErlangAtom CODE_ATOM = atom("code"); + + private static final OtpErlangAtom RETURN_FROM_ATOM = atom("return_from"); private static final OtpErlangAtom EXCEPTION_FROM_ATOM = new OtpErlangAtom("exception_from"); @@ -48,6 +55,8 @@ public class TraceManager { */ private RpcCallback traceLogCallback; + private RpcCallback moduleLoadedCallback; + public List collateTraces(OtpErlangList traceLogs) { final ArrayList traceList = new ArrayList(); @@ -64,11 +73,32 @@ public List collateTraceSingle(OtpErlangTuple traceLog) { return traceList; } + TraceTuple traceTuple = new TraceTuple(); + private void decodeTraceLog(OtpErlangObject otpErlangObject, ArrayList traceList) { + traceTuple.tuple = (OtpErlangTuple) otpErlangObject; OtpErlangTuple tup = (OtpErlangTuple) otpErlangObject; - OtpErlangAtom traceType = (OtpErlangAtom) tup.elementAt(2); + OtpErlangAtom traceType = traceTuple.getTraceType(); if(CALL_ATOM.equals(traceType)) { + OtpErlangAtom moduleLoad = traceTuple.isModuleLoad(); + if(moduleLoad != null) { + // if a module is reloaded then we need to reload the functions for it + // since some may be added or deleted. We also need to reapply traces + // since a reload removes all traces on that module + System.out.println("code reload"); + ErlyBerly.runIO(() -> { + try { + OtpErlangTuple moduleFunctions = ErlyBerly.nodeAPI().moduleFunctions(moduleLoad); + Platform.runLater(() -> { moduleLoadedCallback.callback(moduleFunctions); }); + } + catch (Exception e) { + e.printStackTrace(); + } + }); + // don't show the module load to the user as a trace in the table + return; + } TraceLog trace = proplistToTraceLog(tup); Stack stack = unfinishedCalls.get(trace.getPid()); @@ -91,6 +121,7 @@ else if(RETURN_FROM_ATOM.equals(traceType) || EXCEPTION_FROM_ATOM.equals(traceTy return; TraceLog traceLog = stack.pop(); traceLog.complete(tup, ErlyBerly.getTermFormatter()); + if(stack.isEmpty()) unfinishedCalls.remove(tracedPid); } @@ -99,6 +130,34 @@ else if(RETURN_FROM_ATOM.equals(traceType) || EXCEPTION_FROM_ATOM.equals(traceTy } } + static class TraceTuple { + private static final OtpErlangAtom TRY_LOAD_MODULE_ATOM = atom("try_load_module"); + private static final OtpErlangAtom CODE_SERVER_ATOM = atom("code_server"); + OtpErlangTuple tuple; + + OtpErlangAtom getTraceType() { + return (OtpErlangAtom) tuple.elementAt(2); + } + + private OtpErlangAtom isModuleLoad() { + if(!CALL_ATOM.equals(getTraceType())) + return null; + OtpErlangTuple mfa = getMFA(); + OtpErlangObject mod = mfa.elementAt(0); + OtpErlangObject function = mfa.elementAt(1); + OtpErlangList args = (OtpErlangList) mfa.elementAt(2); + if(CODE_SERVER_ATOM.equals(mod) && TRY_LOAD_MODULE_ATOM.equals(function)) { + System.out.println("TRY_LOAD_MODULE " + tuple); + return (OtpErlangAtom) args.elementAt(1); + } + return null; + } + + private OtpErlangTuple getMFA() { + return (OtpErlangTuple) tuple.elementAt(3); + } + } + private TraceLog proplistToTraceLog(OtpErlangTuple tup) { TraceLog trace = new TraceLog(tup, ErlyBerly.getTermFormatter()); @@ -112,4 +171,9 @@ public RpcCallback getTraceLogCallback() { public void setTraceLogCallback(RpcCallback traceLogCallback) { this.traceLogCallback = traceLogCallback; } + + public void setModuleLoadedCallback(RpcCallback aModuleLoadedCallback) { + moduleLoadedCallback = aModuleLoadedCallback; + + } } diff --git a/src/main/java/erlyberly/node/TraceServerConnection.java b/src/main/java/erlyberly/node/TraceServerConnection.java index ecd90b5..33d3e5a 100644 --- a/src/main/java/erlyberly/node/TraceServerConnection.java +++ b/src/main/java/erlyberly/node/TraceServerConnection.java @@ -34,6 +34,7 @@ private void run() { FileOutputStream outStream = null; buffer = new byte[DEFAULT_BUFFER_SIZE]; int read = 0; + OtpErlangObject traceTerm = null; try { inStream = new BufferedInputStream(socket.getInputStream()); outStream = new FileOutputStream("/tmp/erlyberlytrace"); @@ -62,7 +63,7 @@ private void run() { read = inStream.read(buffer, offset, size); assert read == size : "read: " + read + " size: " + size; OtpInputStream otpInputStream = new OtpInputStream(buffer, offset, size, 0); - OtpErlangObject traceTerm = otpInputStream.read_any(); + traceTerm = otpInputStream.read_any(); assert traceTerm instanceof OtpErlangTuple : traceTerm; traceManager.collateTraceSingle((OtpErlangTuple) traceTerm); otpInputStream.close(); @@ -71,9 +72,11 @@ private void run() { } } catch (Exception e) { + System.out.println("Last traced term was: " + traceTerm); e.printStackTrace(); } finally { + System.out.println("Last traced term was: " + traceTerm); safeCloseStream(outStream); } } diff --git a/src/main/resources/erlyberly/beam/erlyberly.erl b/src/main/resources/erlyberly/beam/erlyberly.erl index 3880d40..0dc6275 100644 --- a/src/main/resources/erlyberly/beam/erlyberly.erl +++ b/src/main/resources/erlyberly/beam/erlyberly.erl @@ -17,16 +17,17 @@ -module(erlyberly). +-export([all_module_functions/0]). -export([collect_seq_trace_logs/0]). -export([ensure_dbg_started/3]). -export([ensure_xref_started/0]). --export([saleyn_fun_src/1]). -export([get_abstract_code/1]). -export([get_process_state/1]). -export([get_source_code/1]). -export([load_modules_on_path/1]). --export([module_functions/0]). +-export([module_functions/1]). -export([process_info/0]). +-export([saleyn_fun_src/1]). -export([seq_trace/5]). -export([start_trace/5]). -export([stop_trace/4]). @@ -157,15 +158,19 @@ record_fields([]) -> %%% module function tree %%% ============================================================================ -module_functions() -> +%% return a list of all modules and their exported and unexported functions +all_module_functions() -> lists:sort( - [module_functions2(Mod) || {Mod, _FPath} <- code:all_loaded()] + [begin + {ok,Result} = module_functions(Mod), + Result + end || {Mod, _FPath} <- code:all_loaded()] ). -module_functions2(Mod) when is_atom(Mod) -> +module_functions(Mod) when is_atom(Mod) -> Exports = Mod:module_info(exports), Unexported = [F || F <- Mod:module_info(functions), not lists:member(F, Exports)], - {Mod, Exports, Unexported}. + {ok,{Mod, Exports, Unexported}}. %%% ============================================================================ @@ -176,17 +181,11 @@ module_functions2(Mod) when is_atom(Mod) -> start_trace({Node, Pid}, Mod, Func, Arity, Max_queue_len) when is_atom(Node), is_pid(Pid), is_integer(Max_queue_len) -> - Ref = make_ref(), - erlyberly_tcollector ! {start_trace, Mod, Func, Arity, self(), Ref}, - receive - {ok, Ref} -> - {ok, whereis(erlyberly_tcollector)}; - Error when element(1,Error) == error -> - Error - after - 1000 -> - {error, timeout} - end. + Match_spec = [{'_', [], [{message,{process_dump}}, {exception_trace}]}], + Trace_spec = {Mod, Func, Arity}, + {ok,_} = dbg:tpl(Trace_spec, Match_spec), + {ok,_} = dbg:p(all, [c, timestamp]), + ok. %% stop_trace(Mod, Func, Arity, _IsExported) -> @@ -213,9 +212,17 @@ ensure_dbg_started({Eb_Node, Eb_pid}, Port, Max_queue_len) when is_integer(Port) {ok,_} = dbg:start(), {ok,_} = dbg:tracer(port, dbg:trace_port(ip, {Port, Max_queue_len})), {ok,_} = dbg:p(all, [c, timestamp]), - {ok,_} = dbg:tp({code, ensure_loaded, 1}, c), + {ok,_} = dbg:tpl({code_server, try_load_module, '_'}, []), + proc_lib:spawn(fun() -> monitor_erlyberly_node(Eb_Node) end), ok. +monitor_erlyberly_node(Node_name) -> + true = erlang:monitor_node(Node_name, true), + receive + {nodedown, Node_name} -> + dbg:stop_clear() + end. + % receive_next_trace(#tcollector{ traces = Traces } = TC) -> % receive % {start_trace, Mod, Func, Arity, Requester, Ref} when is_pid(Requester), From 2b445a27217dc4f82b26b4a9de34fb63a302e6db Mon Sep 17 00:00:00 2001 From: Andy Till Date: Fri, 20 Oct 2017 00:16:21 +0100 Subject: [PATCH 04/10] Track which processes are registered so that the registered name for a process trace can be shown in the UI --- src/main/java/erlyberly/CrashReport.java | 4 +- src/main/java/erlyberly/ProcInfo.java | 3 +- src/main/java/erlyberly/SeqTraceLog.java | 2 +- src/main/java/erlyberly/TopBarView.java | 6 +- src/main/java/erlyberly/TraceLog.java | 10 ++- src/main/java/erlyberly/node/Atoms.java | 36 ++++++++ src/main/java/erlyberly/node/NodeAPI.java | 10 ++- src/main/java/erlyberly/node/OtpUtil.java | 4 +- .../java/erlyberly/node/TraceManager.java | 89 ++++++++++++++----- .../resources/erlyberly/beam/erlyberly.erl | 12 ++- 10 files changed, 138 insertions(+), 38 deletions(-) create mode 100644 src/main/java/erlyberly/node/Atoms.java diff --git a/src/main/java/erlyberly/CrashReport.java b/src/main/java/erlyberly/CrashReport.java index 4ff99d8..75470ae 100644 --- a/src/main/java/erlyberly/CrashReport.java +++ b/src/main/java/erlyberly/CrashReport.java @@ -47,7 +47,7 @@ public class CrashReport { private static final OtpErlangAtom ATOM_LINE = OtpUtil.atom("line"); - private final Map crashProps; + private final Map crashProps; private final String registeredName; @@ -89,7 +89,7 @@ List mapStackTraces(StackTraceFn fn) { OtpErlangList list = (OtpErlangList) argsOrArity; arity = new OtpErlangLong(list.arity()); } - Map fileLineProps = OtpUtil.propsToMap((OtpErlangList) tuple.elementAt(3)); + Map fileLineProps = OtpUtil.propsToMap((OtpErlangList) tuple.elementAt(3)); OtpErlangString file = (OtpErlangString) fileLineProps.get(ATOM_FILE); OtpErlangLong line = (OtpErlangLong) fileLineProps.get(ATOM_LINE); diff --git a/src/main/java/erlyberly/ProcInfo.java b/src/main/java/erlyberly/ProcInfo.java index 9563d56..d2d299c 100644 --- a/src/main/java/erlyberly/ProcInfo.java +++ b/src/main/java/erlyberly/ProcInfo.java @@ -23,6 +23,7 @@ import com.ericsson.otp.erlang.OtpErlangAtom; import com.ericsson.otp.erlang.OtpErlangList; import com.ericsson.otp.erlang.OtpErlangLong; +import com.ericsson.otp.erlang.OtpErlangObject; import com.ericsson.otp.erlang.OtpErlangString; import javafx.beans.property.LongProperty; @@ -165,7 +166,7 @@ public LongProperty reductionsProperty() { return reductions; } - public static ProcInfo toProcessInfo(Map propList) { + public static ProcInfo toProcessInfo(Map propList) { Object processName = propList.get(REGISTERED_NAME_ATOM); Object pid = ((OtpErlangString) propList.get(PID_ATOM)).stringValue(); diff --git a/src/main/java/erlyberly/SeqTraceLog.java b/src/main/java/erlyberly/SeqTraceLog.java index 2b27f5d..bc67860 100644 --- a/src/main/java/erlyberly/SeqTraceLog.java +++ b/src/main/java/erlyberly/SeqTraceLog.java @@ -42,7 +42,7 @@ public SeqTraceLog(Object msgType, Object serial, Object from, Object to, Object this.timestamp = timestamp; } - public static SeqTraceLog build(Map props) { + public static SeqTraceLog build(Map props) { Object msgType = props.get(OtpUtil.atom("msg_type")); Object serial = props.get(OtpUtil.atom("serial")); Object from = props.get(OtpUtil.atom("from")); diff --git a/src/main/java/erlyberly/TopBarView.java b/src/main/java/erlyberly/TopBarView.java index c2862e7..66d588d 100644 --- a/src/main/java/erlyberly/TopBarView.java +++ b/src/main/java/erlyberly/TopBarView.java @@ -521,7 +521,7 @@ public ErlangMemoryThread(ObservableList thePieData) { @Override public void run() { try { - final Map erlangMemory = ErlyBerly.nodeAPI().erlangMemory(); + final Map erlangMemory = ErlyBerly.nodeAPI().erlangMemory(); // remove stats which are combinations of other stats erlangMemory.remove(OtpUtil.atom("maximum")); @@ -539,8 +539,8 @@ public void run() { } } - private void populatePieData(final Map erlangMemory) { - for (Entry entry : erlangMemory.entrySet()) { + private void populatePieData(final Map erlangMemory) { + for (Entry entry : erlangMemory.entrySet()) { long kb = (long) (Double.parseDouble(entry.getValue().toString()) / 1024); String label = entry.getKey().toString() + " (" + kb + " KB)"; pieData.add(new Data(label, kb)); diff --git a/src/main/java/erlyberly/TraceLog.java b/src/main/java/erlyberly/TraceLog.java index 73414d5..da21122 100644 --- a/src/main/java/erlyberly/TraceLog.java +++ b/src/main/java/erlyberly/TraceLog.java @@ -19,6 +19,7 @@ import static erlyberly.node.OtpUtil.atom; +import java.util.HashMap; import java.util.concurrent.atomic.AtomicLong; import com.ericsson.otp.erlang.OtpErlangAtom; @@ -80,7 +81,7 @@ public class TraceLog implements Comparable { private OtpErlangObject resultTerm; - public TraceLog(OtpErlangTuple tuple, TermFormatter formatter) { + public TraceLog(OtpErlangTuple tuple, HashMap registeredProcesses, TermFormatter formatter) { instanceNum = INSTANCE_COUNTER.incrementAndGet(); cssClass = null; // FIXME we don't know the registered name from the info we get from the file @@ -91,6 +92,13 @@ public TraceLog(OtpErlangTuple tuple, TermFormatter formatter) { assert TRACE_TS.equals(messageType) : messageType; assert tuple.elementAt(1) instanceof OtpErlangPid : tuple.elementAt(1); pid = (OtpErlangPid) tuple.elementAt(1); + OtpErlangAtom aRegName = registeredProcesses.get(pid); + if(aRegName == null) { + registeredName = ""; + } + else { + registeredName = aRegName.atomValue(); + } pidString = formatter.toString(tuple.elementAt(1)); // we only accept trace types of `call` in the constructor OtpErlangObject traceType = tuple.elementAt(2); diff --git a/src/main/java/erlyberly/node/Atoms.java b/src/main/java/erlyberly/node/Atoms.java new file mode 100644 index 0000000..b1b79b7 --- /dev/null +++ b/src/main/java/erlyberly/node/Atoms.java @@ -0,0 +1,36 @@ +/** + * erlyberly, erlang trace debugger + * Copyright (C) 2016 Andy Till + * + * This program is free software: you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation, either version 3 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with this program. If not, see . + */ +package erlyberly.node; + +import static erlyberly.node.OtpUtil.atom; + +import com.ericsson.otp.erlang.OtpErlangAtom; + +/** + * Atom constants. + */ +public class Atoms { + public static final OtpErlangAtom ERLANG_ATOM = atom("erlang"); + public static final OtpErlangAtom REGISTER_ATOM = atom("register"); + public static final OtpErlangAtom CODE_SERVER_ATOM = atom("code_server"); + public static final OtpErlangAtom TRY_LOAD_MODULE_ATOM = atom("try_load_module"); + public static final OtpErlangAtom RETURN_FROM_ATOM = atom("return_from"); + public static final OtpErlangAtom EXCEPTION_FROM_ATOM = atom("exception_from"); + public static final OtpErlangAtom CALL_ATOM = atom("call"); + public static final OtpErlangAtom UNREGISTER_ATOM = atom("unregister"); +} diff --git a/src/main/java/erlyberly/node/NodeAPI.java b/src/main/java/erlyberly/node/NodeAPI.java index 51041a4..a09624e 100644 --- a/src/main/java/erlyberly/node/NodeAPI.java +++ b/src/main/java/erlyberly/node/NodeAPI.java @@ -282,6 +282,12 @@ private synchronized void ensureDbgStarted() throws IOException, OtpErlangExcept if(!isSuccessTerm(returnedObject)) { throw new RuntimeException(returnedObject.toString()); } + assert returnedObject instanceof OtpErlangTuple : returnedObject; + OtpErlangTuple returnedTuple = (OtpErlangTuple) returnedObject; + OtpErlangObject regNames = returnedTuple.elementAt(1); + assert regNames instanceof OtpErlangList : regNames; + Map regNamesMap = OtpUtil.propsToMap((OtpErlangList) regNames); + traceManager.setRegisteredProcesses(regNamesMap); } private boolean isSuccessTerm(OtpErlangObject term) { @@ -476,7 +482,7 @@ public synchronized void retrieveProcessInfo(List processes) { for (OtpErlangObject recv : received) { if(recv instanceof OtpErlangList) { OtpErlangList pinfo = (OtpErlangList) recv; - Map propsToMap = OtpUtil.propsToMap(pinfo); + Map propsToMap = OtpUtil.propsToMap(pinfo); processes.add(ProcInfo.toProcessInfo(propsToMap)); } } @@ -669,7 +675,7 @@ public synchronized OtpErlangObject getProcessState(String pidString) throws IOE return null; } - public synchronized Map erlangMemory() throws IOException, OtpErlangException { + public synchronized Map erlangMemory() throws IOException, OtpErlangException { assert !Platform.isFxApplicationThread() : CANNOT_RUN_THIS_METHOD_FROM_THE_FX_THREAD; OtpErlangObject result = nodeRPC().blockingRPC(atom("erlang"), atom("memory"), list()); assert result instanceof OtpErlangList : result; diff --git a/src/main/java/erlyberly/node/OtpUtil.java b/src/main/java/erlyberly/node/OtpUtil.java index e832005..a2089b3 100644 --- a/src/main/java/erlyberly/node/OtpUtil.java +++ b/src/main/java/erlyberly/node/OtpUtil.java @@ -114,8 +114,8 @@ public static OtpErlangAtom atom(String name) { /** * Take an {@link OtpErlangList} of erlang key value tuples and converts it to a map. */ - public static Map propsToMap(OtpErlangList pinfo) { - HashMap map = new HashMap<>(); + public static Map propsToMap(OtpErlangList pinfo) { + HashMap map = new HashMap<>(); for (OtpErlangObject otpErlangObject : pinfo) { if(otpErlangObject instanceof OtpErlangTuple && ((OtpErlangTuple) otpErlangObject).arity() == 2) { OtpErlangTuple tuple = ((OtpErlangTuple) otpErlangObject); diff --git a/src/main/java/erlyberly/node/TraceManager.java b/src/main/java/erlyberly/node/TraceManager.java index 1aa5031..6ff2556 100644 --- a/src/main/java/erlyberly/node/TraceManager.java +++ b/src/main/java/erlyberly/node/TraceManager.java @@ -17,11 +17,11 @@ */ package erlyberly.node; -import static erlyberly.node.OtpUtil.atom; - import java.util.ArrayList; import java.util.HashMap; import java.util.List; +import java.util.Map; +import java.util.Map.Entry; import java.util.Stack; import com.ericsson.otp.erlang.OtpErlangAtom; @@ -36,17 +36,23 @@ public class TraceManager { - private static final OtpErlangAtom MODULE_ATOM = atom("module"); - - private static final OtpErlangAtom CODE_ATOM = atom("code"); - - private static final OtpErlangAtom RETURN_FROM_ATOM = atom("return_from"); - - private static final OtpErlangAtom EXCEPTION_FROM_ATOM = new OtpErlangAtom("exception_from"); + private final HashMap> unfinishedCalls = new HashMap>(); - private static final OtpErlangAtom CALL_ATOM = new OtpErlangAtom("call"); + /** + * A map from processes to their registered name. It is updated when + * erlang:register/2 and erlang:unregister/1 calls are made, which are + * traced when dbg is started. + * + * When a process goes down, it is not unregistered which means we may + * end up with a lot of keys which are dead processes! FIXME + */ + private final HashMap registeredProcesses = new HashMap<>(); - private final HashMap> unfinishedCalls = new HashMap>(); + /** + * A wrapper for trace tuples to give an API, rather than pull values + * from the tuple. + */ + private final TraceTuple traceTuple = new TraceTuple(); /** * Called when a trace log is received. @@ -73,14 +79,12 @@ public List collateTraceSingle(OtpErlangTuple traceLog) { return traceList; } - TraceTuple traceTuple = new TraceTuple(); - private void decodeTraceLog(OtpErlangObject otpErlangObject, ArrayList traceList) { traceTuple.tuple = (OtpErlangTuple) otpErlangObject; OtpErlangTuple tup = (OtpErlangTuple) otpErlangObject; OtpErlangAtom traceType = traceTuple.getTraceType(); - if(CALL_ATOM.equals(traceType)) { + if(Atoms.CALL_ATOM.equals(traceType)) { OtpErlangAtom moduleLoad = traceTuple.isModuleLoad(); if(moduleLoad != null) { // if a module is reloaded then we need to reload the functions for it @@ -99,6 +103,9 @@ private void decodeTraceLog(OtpErlangObject otpErlangObject, ArrayList // don't show the module load to the user as a trace in the table return; } + else if(traceTuple.isProcessRegistration()) { + return; + } TraceLog trace = proplistToTraceLog(tup); Stack stack = unfinishedCalls.get(trace.getPid()); @@ -113,7 +120,7 @@ private void decodeTraceLog(OtpErlangObject otpErlangObject, ArrayList if(traceLogCallback != null) traceLogCallback.callback(trace); } - else if(RETURN_FROM_ATOM.equals(traceType) || EXCEPTION_FROM_ATOM.equals(traceType)) { + else if(Atoms.RETURN_FROM_ATOM.equals(traceType) || Atoms.EXCEPTION_FROM_ATOM.equals(traceType)) { assert tup.elementAt(1) instanceof OtpErlangPid; OtpErlangPid tracedPid = (OtpErlangPid) tup.elementAt(1); Stack stack = unfinishedCalls.get(tracedPid); @@ -130,9 +137,7 @@ else if(RETURN_FROM_ATOM.equals(traceType) || EXCEPTION_FROM_ATOM.equals(traceTy } } - static class TraceTuple { - private static final OtpErlangAtom TRY_LOAD_MODULE_ATOM = atom("try_load_module"); - private static final OtpErlangAtom CODE_SERVER_ATOM = atom("code_server"); + class TraceTuple { OtpErlangTuple tuple; OtpErlangAtom getTraceType() { @@ -140,26 +145,59 @@ OtpErlangAtom getTraceType() { } private OtpErlangAtom isModuleLoad() { - if(!CALL_ATOM.equals(getTraceType())) + if(!Atoms.CALL_ATOM.equals(getTraceType())) return null; OtpErlangTuple mfa = getMFA(); OtpErlangObject mod = mfa.elementAt(0); OtpErlangObject function = mfa.elementAt(1); OtpErlangList args = (OtpErlangList) mfa.elementAt(2); - if(CODE_SERVER_ATOM.equals(mod) && TRY_LOAD_MODULE_ATOM.equals(function)) { - System.out.println("TRY_LOAD_MODULE " + tuple); + if(Atoms.CODE_SERVER_ATOM.equals(mod) && Atoms.TRY_LOAD_MODULE_ATOM.equals(function)) { return (OtpErlangAtom) args.elementAt(1); } return null; } + private boolean isProcessRegistration() { + if(!Atoms.CALL_ATOM.equals(getTraceType())) + return false; + OtpErlangTuple mfa = getMFA(); + OtpErlangObject mod = mfa.elementAt(0); + OtpErlangObject function = mfa.elementAt(1); + OtpErlangList args = (OtpErlangList) mfa.elementAt(2); + if(!Atoms.ERLANG_ATOM.equals(mod)) + return false; + if(Atoms.REGISTER_ATOM.equals(function)) { + OtpErlangAtom regName = (OtpErlangAtom) args.elementAt(0); + OtpErlangPid regPid = (OtpErlangPid) args.elementAt(1); + registeredProcesses.put(regPid, regName); + return true; + } + else if(Atoms.UNREGISTER_ATOM.equals(function)) { + OtpErlangAtom regName = (OtpErlangAtom) args.elementAt(0); + OtpErlangPid regPid = null; + for (Entry e : registeredProcesses.entrySet()) { + if(regName.equals(e.getValue())) { + regPid = e.getKey(); + continue; + } + } + // do not try to remove the entry from within the loop because that may thrown + // a ConcurrentModificationException + if(regPid != null) { + registeredProcesses.remove(regPid); + } + return true; + } + return false; + } + private OtpErlangTuple getMFA() { return (OtpErlangTuple) tuple.elementAt(3); } } private TraceLog proplistToTraceLog(OtpErlangTuple tup) { - TraceLog trace = new TraceLog(tup, ErlyBerly.getTermFormatter()); + TraceLog trace = new TraceLog(tup, registeredProcesses, ErlyBerly.getTermFormatter()); return trace; } @@ -176,4 +214,11 @@ public void setModuleLoadedCallback(RpcCallback aModuleLoadedCal moduleLoadedCallback = aModuleLoadedCallback; } + + public void setRegisteredProcesses(Map regProcs) { + registeredProcesses.clear(); + for (Entry e : regProcs.entrySet()) { + registeredProcesses.put((OtpErlangPid)e.getKey(), (OtpErlangAtom)e.getValue()); + } + } } diff --git a/src/main/resources/erlyberly/beam/erlyberly.erl b/src/main/resources/erlyberly/beam/erlyberly.erl index 0dc6275..ccaaf12 100644 --- a/src/main/resources/erlyberly/beam/erlyberly.erl +++ b/src/main/resources/erlyberly/beam/erlyberly.erl @@ -206,15 +206,19 @@ when_process_is_unregistered(ProcName, Fn) -> %% ensure_dbg_started({Eb_Node, Eb_pid}, Port, Max_queue_len) when is_integer(Port), is_integer(Max_queue_len) -> - %% FIXME we still need a process to monitor the erlyberly node going down, - %% and stop dbg if it does. ok = dbg:stop(), {ok,_} = dbg:start(), + proc_lib:spawn(fun() -> monitor_erlyberly_node(Eb_Node) end), {ok,_} = dbg:tracer(port, dbg:trace_port(ip, {Port, Max_queue_len})), {ok,_} = dbg:p(all, [c, timestamp]), + %% trace when a module is loaded so that the traces can be reapplied {ok,_} = dbg:tpl({code_server, try_load_module, '_'}, []), - proc_lib:spawn(fun() -> monitor_erlyberly_node(Eb_Node) end), - ok. + %% always trace process registrations because we need to track them so that + %% they can be shown in the ui + {ok,_} = dbg:tpl({erlang, register, '_'}, []), + {ok,_} = dbg:tpl({erlang, unregister, '_'}, []), + Registered_procs = [{whereis(Name), Name} || Name <- erlang:registered()], + {ok, Registered_procs}. monitor_erlyberly_node(Node_name) -> true = erlang:monitor_node(Node_name, true), From 4d59ab576d2cdc5def5ba43600e6139e5f56a828 Mon Sep 17 00:00:00 2001 From: Andy Till Date: Fri, 20 Oct 2017 00:17:24 +0100 Subject: [PATCH 05/10] Delete commented code. --- .../resources/erlyberly/beam/erlyberly.erl | 91 ------------------- 1 file changed, 91 deletions(-) diff --git a/src/main/resources/erlyberly/beam/erlyberly.erl b/src/main/resources/erlyberly/beam/erlyberly.erl index ccaaf12..d2ae4fa 100644 --- a/src/main/resources/erlyberly/beam/erlyberly.erl +++ b/src/main/resources/erlyberly/beam/erlyberly.erl @@ -227,97 +227,6 @@ monitor_erlyberly_node(Node_name) -> dbg:stop_clear() end. -% receive_next_trace(#tcollector{ traces = Traces } = TC) -> -% receive -% {start_trace, Mod, Func, Arity, Requester, Ref} when is_pid(Requester), -% is_reference(Ref) -> -% TC1 = tcollector_start_trace(Mod, Func, Arity, TC), -% Requester ! {ok, Ref}, -% erlyberly_tcollector2(TC1); -% {stop_trace, Mod, Func, Arity} -> -% dbg:ctpl(Mod, Func, Arity), -% Traces_1 = Traces -- [{Mod, Func, Arity}], -% TC1 = TC#tcollector{ traces = Traces_1 }, -% erlyberly_tcollector2(TC1); -% stop_traces -> -% ok = dbg:stop_clear(); -% {nodedown, _Node} -> -% ok = dbg:stop_clear(); -% Log -> -% case collect_log(Log) of -% skip -> -% ok; -% {erlyberly_module_loaded, Loaded_module} -> -% ok = reapply_traces(Loaded_module, TC#tcollector.traces), -% ok = notify_erlyberly_module_loaded(Loaded_module, TC); -% Trace_log -> -% notify_erlyberly_trace_log(Trace_log, TC) -% end, -% erlyberly_tcollector2(TC) -% end. - -% %% -% tcollector_start_trace(Mod, Func, Arity, #tcollector{ traces = Traces } = TC) -> -% Match_spec = [{'_', [], [{message,{process_dump}}, {exception_trace}]}], -% Trace_spec = {Mod, Func, Arity}, -% dbg:tpl(Trace_spec, Match_spec), -% dbg:p(all, [c, timestamp]), -% TC#tcollector{ traces = [Trace_spec | Traces] }. - -%% -% collect_log({trace_ts, _, return_from, {code, ensure_loaded, _}, _}) -> -% % ensure loaded can be called many times for one reload so just skip it -% skip; -% collect_log({trace_ts, _, return_from, {code, _, _}, {module, Loaded_module}, _}) -> -% % if we trace that a module is reloaded then reapply traces to it -% %ok = reapply_traces(Loaded_module, TC#tcollector.traces), -% %ok = notify_erlyberly_module_loaded(Loaded_module, TC), -% {erlyberly_module_loaded, Loaded_module}; -% collect_log({trace_ts, _, _, {code, _, _}, _}) -> -% skip; -% collect_log({trace_ts, _, _, {code, _, _}}) -> -% skip; -% collect_log(Trace) when element(1, Trace) == trace_ts orelse element(1, Trace) == trace -> -% trace_to_props(Trace); -% collect_log(U) -> -% io:format("unknown trace ~p~n", [U]), -% skip. - -% notify_erlyberly_module_loaded(Loaded_module, #tcollector{ ui_pid = Pid }) -> -% Pid ! {erlyberly_module_loaded, Loaded_module, module_functions2(Loaded_module)}, -% ok. - -% notify_erlyberly_trace_log(Trace_log, #tcollector{ ui_pid = Pid }) -> -% Pid ! {erlyberly_trace_log, Trace_log}, -% ok. - -%% -% reapply_traces(Loaded_module, Traces) -> -% % filter out the traces for the reloaded, module, could be -% % done in the list comp but it causes a compiler warning -% Traces_1 = lists:filter(fun(T) -> -% element(1, T) == Loaded_module -% end, Traces), - -% % reapply each trace that has the loaded module -% [erlyberly_tcollector ! {start_trace, M, F, A, self(), make_ref()} || {M, F, A} <- Traces_1], -% ok. - -%% -% collect_trace_logs() -> -% case whereis(erlyberly_tcollector) of -% undefined -> -% % monitoring of a pid from jinterface is not implemented as far as I can -% % tell so just make do with polling -% {error, tcollector_down}; -% _ -> -% erlyberly_tcollector ! {take_logs, self()}, -% receive -% {trace_logs, Logs} -> {ok, Logs} -% after 2000 -> {error, tcollector_timeout} -% end -% end. - %%% ============================================================================= %%% %%% seq_trace From 5a40e8b97bc67ad5aae9df39a11c51d48b565893 Mon Sep 17 00:00:00 2001 From: Andy Till Date: Fri, 20 Oct 2017 01:00:41 +0100 Subject: [PATCH 06/10] Do not put #Pid before the pid angle brackets in the pid to string. --- src/main/java/erlyberly/format/ErlangFormatter.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/main/java/erlyberly/format/ErlangFormatter.java b/src/main/java/erlyberly/format/ErlangFormatter.java index 380bbca..1f6f107 100644 --- a/src/main/java/erlyberly/format/ErlangFormatter.java +++ b/src/main/java/erlyberly/format/ErlangFormatter.java @@ -88,7 +88,7 @@ else if(obj instanceof OtpErlangString) { } private static String pidToString(OtpErlangPid pid) { - return pid.toString(); + return "<" + pid.node().toString() + "." + pid.id() + "." + pid.serial() + ">"; } public String bracketsForTerm(OtpErlangObject obj) { From 56cfb4a24f3679c28c2217c5d03863e133b611f1 Mon Sep 17 00:00:00 2001 From: Andy Till Date: Fri, 20 Oct 2017 01:01:33 +0100 Subject: [PATCH 07/10] Fixes #148 where the filter is broken, the filter was being applied against an object to string instead of actual trace data. --- src/main/java/erlyberly/DbgTraceView.java | 12 ++++++++---- 1 file changed, 8 insertions(+), 4 deletions(-) diff --git a/src/main/java/erlyberly/DbgTraceView.java b/src/main/java/erlyberly/DbgTraceView.java index 2a985bd..095280c 100644 --- a/src/main/java/erlyberly/DbgTraceView.java +++ b/src/main/java/erlyberly/DbgTraceView.java @@ -99,7 +99,7 @@ private void putTableColumns() { TableColumn pidColumn; pidColumn = new TableColumn("Pid"); - pidColumn.setCellValueFactory(new PropertyValueFactory("pid")); + pidColumn.setCellValueFactory(new PropertyValueFactory("pidString")); configureColumnWidth("pidColumnWidth", pidColumn); TableColumn regNameColumn; @@ -270,10 +270,14 @@ private Node labelledTreeView(String label, TermTreeView node) { } private void onTraceFilterChange(String searchText) { - BasicSearch basicSearch = new BasicSearch(searchText); + BasicSearch search = new BasicSearch(searchText); filteredTraces.setPredicate((t) -> { - String logText = t.toString(); - return basicSearch.matches(logText); + boolean matches = + search.matches(t.getArgs()) + || search.matches(t.getResult()) + || search.matches(t.getPidString()) + || search.matches(t.getRegName()); + return matches; }); } From 2cdf58af57db4381239dd76f4232eb6bdee728b0 Mon Sep 17 00:00:00 2001 From: Andy Till Date: Fri, 20 Oct 2017 17:24:45 +0100 Subject: [PATCH 08/10] More on #148, filter on the function m:f/a --- src/main/java/erlyberly/DbgTraceView.java | 1 + 1 file changed, 1 insertion(+) diff --git a/src/main/java/erlyberly/DbgTraceView.java b/src/main/java/erlyberly/DbgTraceView.java index 095280c..2ddc7e1 100644 --- a/src/main/java/erlyberly/DbgTraceView.java +++ b/src/main/java/erlyberly/DbgTraceView.java @@ -274,6 +274,7 @@ private void onTraceFilterChange(String searchText) { filteredTraces.setPredicate((t) -> { boolean matches = search.matches(t.getArgs()) + || search.matches(t.getFunction()) || search.matches(t.getResult()) || search.matches(t.getPidString()) || search.matches(t.getRegName()); From 84285678ba08393fda72eae1e6ff945a655a78b3 Mon Sep 17 00:00:00 2001 From: Andy Till Date: Fri, 20 Oct 2017 17:54:21 +0100 Subject: [PATCH 09/10] Make stack traces work again now that we receive traces from ports. This was broken because we receive the stack trace as a binary and there is no middle man process to decode it. Now, we store the binary and then send it back to the remote node via rpc to be decoded when we need to view it, and cache that. --- src/main/java/erlyberly/DbgTraceView.java | 36 +++++++++++++++---- src/main/java/erlyberly/TraceLog.java | 19 +++++++++- src/main/java/erlyberly/node/NodeAPI.java | 9 ++++- .../resources/erlyberly/beam/erlyberly.erl | 1 + 4 files changed, 56 insertions(+), 9 deletions(-) diff --git a/src/main/java/erlyberly/DbgTraceView.java b/src/main/java/erlyberly/DbgTraceView.java index 2ddc7e1..499584a 100644 --- a/src/main/java/erlyberly/DbgTraceView.java +++ b/src/main/java/erlyberly/DbgTraceView.java @@ -245,14 +245,31 @@ private void showTraceTermView(final TraceLog traceLog) { StackTraceView stackTraceView; stackTraceView = new StackTraceView(); - String stackTraceTitle = "No Stack Trace"; - OtpErlangList stackTrace = traceLog.getStackTrace(); - if(stackTrace != null) { - stackTraceView.populateFromMfaList(stackTrace); - stackTraceTitle = "Stack Trace (" + stackTrace.arity() + ")"; - } TitledPane titledPane; - titledPane = new TitledPane(stackTraceTitle, stackTraceView); + titledPane = new TitledPane("No Stack Trace", stackTraceView); + if(traceLog.getStackTrace() != null) { + applyStackTraceOnView(traceLog, stackTraceView, titledPane); + } + else { + ErlyBerly.runIO(() -> { + OtpErlangList stackTrace; + try { + // if the stack trace is null then send the stack trace binary that we + // receive in the trace tuple to the remote node so that it can be decoded + // since we don't want to rewrite that logic in java. Once we receive the + // stack trace as a list we can set the binary to null so it can be gc'ed + stackTrace = ErlyBerly.nodeAPI().stak(traceLog.getStackTraceBinary()); + Platform.runLater(() -> { + traceLog.setStackTrace(stackTrace); + traceLog.setStackTraceBinary(null); + applyStackTraceOnView(traceLog, stackTraceView, titledPane); + }); + } + catch (Exception e) { + e.printStackTrace(); + } + }); + } titledPane.setExpanded(!stackTraceView.isStackTracesEmpty()); splitPaneH = new SplitPane(); splitPaneH.setOrientation(Orientation.VERTICAL); @@ -265,6 +282,11 @@ private void showTraceTermView(final TraceLog traceLog) { ErlyBerly.showPane(sb.toString(), ErlyBerly.wrapInPane(splitPaneH)); } + private void applyStackTraceOnView(final TraceLog traceLog, StackTraceView stackTraceView, TitledPane titledPane) { + stackTraceView.populateFromMfaList(traceLog.getStackTrace()); + titledPane.setText("Stack Trace (" + traceLog.getStackTrace().arity() + ")"); + } + private Node labelledTreeView(String label, TermTreeView node) { return new VBox(new Label(label), node); } diff --git a/src/main/java/erlyberly/TraceLog.java b/src/main/java/erlyberly/TraceLog.java index da21122..e8fff36 100644 --- a/src/main/java/erlyberly/TraceLog.java +++ b/src/main/java/erlyberly/TraceLog.java @@ -23,6 +23,7 @@ import java.util.concurrent.atomic.AtomicLong; import com.ericsson.otp.erlang.OtpErlangAtom; +import com.ericsson.otp.erlang.OtpErlangBinary; import com.ericsson.otp.erlang.OtpErlangList; import com.ericsson.otp.erlang.OtpErlangLong; import com.ericsson.otp.erlang.OtpErlangObject; @@ -63,11 +64,12 @@ public class TraceLog implements Comparable { private final String cssClass; - // FIXME registeredName private String registeredName = ""; private OtpErlangList stacktrace; + private OtpErlangBinary stackTraceBinary; + private boolean functionThrewException; private ModFunc modFunc; @@ -117,6 +119,9 @@ public TraceLog(OtpErlangTuple tuple, HashMap regis modFunc = new ModFunc( ((OtpErlangAtom)mfa.elementAt(0)).atomValue(), ((OtpErlangAtom)mfa.elementAt(1)).atomValue(), arity, false, false); + // stack trace as a binary + assert tuple.elementAt(4) instanceof OtpErlangBinary : tuple.elementAt(4); + stackTraceBinary = (OtpErlangBinary) tuple.elementAt(4); // the three element tuple timestamp int timestampIndex = tuple.arity()-1; assert tuple.elementAt(timestampIndex) instanceof OtpErlangTuple : "TRACE WAS " + tuple + " timestamp was " + formatter.toString(tuple.elementAt(timestampIndex)); @@ -352,6 +357,10 @@ public OtpErlangList getStackTrace() { return stacktrace; } + public void setStackTrace(OtpErlangList stacktrace) { + this.stacktrace = stacktrace; + } + public ModFunc getModFunc() { return modFunc; } @@ -363,4 +372,12 @@ public String getPidString() { public String getFunction() { return functionString; } + + public OtpErlangBinary getStackTraceBinary() { + return stackTraceBinary; + } + + public void setStackTraceBinary(OtpErlangBinary stackTraceBinary) { + this.stackTraceBinary = stackTraceBinary; + } } diff --git a/src/main/java/erlyberly/node/NodeAPI.java b/src/main/java/erlyberly/node/NodeAPI.java index a09624e..3df4891 100644 --- a/src/main/java/erlyberly/node/NodeAPI.java +++ b/src/main/java/erlyberly/node/NodeAPI.java @@ -786,7 +786,6 @@ public synchronized String decompileFun(OtpErlangFun fun) throws IOException, Ot */ public void loadModule(OtpErlangAtom moduleNameAtom) throws OtpErlangException, IOException { assert moduleNameAtom != null : "module name string is null"; - assert !"".equals(moduleNameAtom) : " module name string is empty"; assert !Platform.isFxApplicationThread() : CANNOT_RUN_THIS_METHOD_FROM_THE_FX_THREAD; // if we already know about this module then there is no to load it again if(knownModules.contains(moduleNameAtom)) @@ -797,6 +796,14 @@ public void loadModule(OtpErlangAtom moduleNameAtom) throws OtpErlangException, knownModules.add(moduleNameAtom); } + public OtpErlangList stak(OtpErlangBinary stackTraceBinary) throws OtpErlangException, IOException { + assert stackTraceBinary != null; + OtpErlangObject result = nodeRPC() + .blockingRPC(atom("erlyberly"), atom("stak"), list(stackTraceBinary)); + assert result instanceof OtpErlangList : result; + return (OtpErlangList) result; + } + public RpcCallback getTraceLogCallback() { return traceManager.getTraceLogCallback(); } diff --git a/src/main/resources/erlyberly/beam/erlyberly.erl b/src/main/resources/erlyberly/beam/erlyberly.erl index d2ae4fa..8ced2c8 100644 --- a/src/main/resources/erlyberly/beam/erlyberly.erl +++ b/src/main/resources/erlyberly/beam/erlyberly.erl @@ -29,6 +29,7 @@ -export([process_info/0]). -export([saleyn_fun_src/1]). -export([seq_trace/5]). +-export([stak/1]). -export([start_trace/5]). -export([stop_trace/4]). -export([stop_traces/0]). From 46de88eed4247a7c83560bcd607ea2e859856cb9 Mon Sep 17 00:00:00 2001 From: andytill Date: Sun, 4 Feb 2018 16:15:45 +0000 Subject: [PATCH 10/10] Fix erlang compile warnings. --- src/main/resources/erlyberly/beam/erlyberly.erl | 9 ++------- 1 file changed, 2 insertions(+), 7 deletions(-) diff --git a/src/main/resources/erlyberly/beam/erlyberly.erl b/src/main/resources/erlyberly/beam/erlyberly.erl index 8ced2c8..eb80372 100644 --- a/src/main/resources/erlyberly/beam/erlyberly.erl +++ b/src/main/resources/erlyberly/beam/erlyberly.erl @@ -198,14 +198,9 @@ stop_traces() -> %% FIXME do a receive to make sure that the call was successful erlyberly_tcollector ! stop_traces, ok. + %% -when_process_is_unregistered(ProcName, Fn) -> - case whereis(ProcName) of - undefined -> Fn(); - _ -> ok - end. -%% -ensure_dbg_started({Eb_Node, Eb_pid}, Port, Max_queue_len) when is_integer(Port), +ensure_dbg_started({Eb_Node, _Eb_pid}, Port, Max_queue_len) when is_integer(Port), is_integer(Max_queue_len) -> ok = dbg:stop(), {ok,_} = dbg:start(),