[SYSTEMDS-3710] Function entry/exit marker in lineage traces

This patch adds a new utility in lineage tracing for debugging and
interpretability. The flat lineage tracing makes it harder to track
calls to built-ins and the arguments (e.g. hyperparameters). To better
structure the lineage traces, we now add function start end markers
for each input and output, respectively. These entries are NOOPs and
do not impact the reuse in any way.
Future tasks include adding similar markers for control flow and
enable deserialization of these markers.
Note, this utility is default disabled and can be enabled using the
flag, LineageItemUtils.FUNCTION_DEBUGGING.

src/main/java/org/apache/sysds/runtime/instructions/cp/FunctionCallCPInstruction.java

@@ -175,9 +175,16 @@ public void processInstruction(ExecutionContext ec) {
 
 			//map lineage to function arguments
 			if( lineage != null ) {
-				LineageItem litem = _lineageInputs == null ? ec.getLineageItem(input) : _lineageInputs[i];
-				lineage.set(currFormalParam.getName(), (litem!=null) ? 
-					litem : ec.getLineage().getOrCreate(input));
+				LineageItem inLitem = _lineageInputs == null ? ec.getLineageItem(input) : _lineageInputs[i];
+				inLitem = inLitem != null ? inLitem : ec.getLineage().getOrCreate(input);
+				if (LineageItemUtils.isFunctionDebugging()) { //add a marker for function call
+					String funcOp = _functionName + LineageItemUtils.FUNC_DELIM + "INP"
+						+ LineageItemUtils.FUNC_DELIM + currFormalParam.getName();
+					LineageItem funcItem = new LineageItem(funcOp, new LineageItem[] {inLitem});
+					lineage.set(currFormalParam.getName(), funcItem);
+				}
+				else
+					lineage.set(currFormalParam.getName(), inLitem);
 			}
 		}
 
@@ -249,8 +256,16 @@ public void processInstruction(ExecutionContext ec) {
 			ec.setVariable(boundVarName, boundValue);
 
 			//map lineage of function returns back to calling site
-			if( lineage != null ) //unchanged ref
-				ec.getLineage().set(boundVarName, lineage.get(retVarName));
+			if( lineage != null ) { //unchanged ref
+				LineageItem outLitem = lineage.get(retVarName);
+				if (LineageItemUtils.isFunctionDebugging()) { //add a marker for function return
+					String funcOp = _functionName + LineageItemUtils.FUNC_DELIM + "RET" + LineageItemUtils.FUNC_DELIM + boundVarName;
+					LineageItem funcItem = new LineageItem(funcOp, new LineageItem[] {outLitem});
+					ec.getLineage().set(boundVarName, funcItem);
+				}
+				else
+					ec.getLineage().set(boundVarName, outLitem);
+			}
 		}
 
 		// cleanup old data bound to output variable names

src/main/java/org/apache/sysds/runtime/lineage/LineageItemUtils.java

@@ -78,6 +78,8 @@
 public class LineageItemUtils {
 
 	public static final String LPLACEHOLDER = "IN#";
+	public static final String FUNC_DELIM = "_";
+	private static final boolean FUNCTION_DEBUGGING = false; //enable for adding function-marker lineage entries
 
 	// opcode to represent the serialized bytes of a federated response in lineage cache
 	public static final String SERIALIZATION_OPCODE = "serialize";
@@ -118,6 +120,10 @@ private static String getString(LineageItemType lit) {
 	private static String getString(LineageItem li) {
 		return getString(li.getType());
 	}
+
+	public static boolean isFunctionDebugging () {
+		return FUNCTION_DEBUGGING;
+	}
 
 	public static String explainSingleLineageItem(LineageItem li) {
 		StringBuilder sb = new StringBuilder();
@@ -151,7 +157,7 @@ public static LineageItem[] getLineage(ExecutionContext ec, CPOperand... operand
 		return Arrays.stream(operands).filter(c -> c!=null)
 			.map(c -> ec.getLineage().getOrCreate(c)).toArray(LineageItem[]::new);
 	}
-	
+
 	public static void traceFedUDF(ExecutionContext ec, FederatedUDF udf) {
 		if (udf.getLineageItem(ec) == null)
 			//TODO: trace all UDFs