8063036: Various pretty printing issues with --log=recompile
Reviewed-by: hannesw, jlaskey
--- a/nashorn/src/jdk.scripting.nashorn/share/classes/jdk/nashorn/internal/runtime/CompiledFunction.java Wed Nov 12 15:13:08 2014 +0100
+++ b/nashorn/src/jdk.scripting.nashorn/share/classes/jdk/nashorn/internal/runtime/CompiledFunction.java Wed Nov 12 17:19:04 2014 +0100
@@ -33,9 +33,11 @@
import java.lang.invoke.MethodType;
import java.lang.invoke.MutableCallSite;
import java.lang.invoke.SwitchPoint;
+import java.util.ArrayList;
import java.util.Collection;
import java.util.Collections;
import java.util.Iterator;
+import java.util.List;
import java.util.Map;
import java.util.TreeMap;
import java.util.function.Supplier;
@@ -726,34 +728,58 @@
* @param ipp
* @return string describing the ipp map
*/
- private static String toStringInvalidations(final Map<Integer, Type> ipp) {
+ private static List<String> toStringInvalidations(final Map<Integer, Type> ipp) {
if (ipp == null) {
- return "";
+ return Collections.emptyList();
}
- final StringBuilder sb = new StringBuilder();
+ final List<String> list = new ArrayList<>();
for (final Iterator<Map.Entry<Integer, Type>> iter = ipp.entrySet().iterator(); iter.hasNext(); ) {
final Map.Entry<Integer, Type> entry = iter.next();
final char bct = entry.getValue().getBytecodeStackType();
+ final String type;
+ switch (entry.getValue().getBytecodeStackType()) {
+ case 'A':
+ type = "object";
+ break;
+ case 'I':
+ type = "int";
+ break;
+ case 'J':
+ type = "long";
+ break;
+ case 'D':
+ type = "double";
+ break;
+ default:
+ type = String.valueOf(bct);
+ break;
+ }
+
+ final StringBuilder sb = new StringBuilder();
sb.append('[').
+ append("program point: ").
append(entry.getKey()).
- append("->").
- append(bct == 'A' ? 'O' : bct).
+ append(" -> ").
+ append(type).
append(']');
- if (iter.hasNext()) {
- sb.append(' ');
- }
+ list.add(sb.toString());
}
- return sb.toString();
+ return list;
}
private void logRecompile(final String reason, final FunctionNode fn, final MethodType type, final Map<Integer, Type> ipp) {
if (log.isEnabled()) {
- log.info(reason, DebugLogger.quote(fn.getName()), " signature: ", type, " ", toStringInvalidations(ipp));
+ log.info(reason, DebugLogger.quote(fn.getName()), " signature: ", type);
+ log.indent();
+ for (final String str : toStringInvalidations(ipp)) {
+ log.fine(str);
+ }
+ log.unindent();
}
}
@@ -769,7 +795,14 @@
*/
private synchronized MethodHandle handleRewriteException(final OptimismInfo oldOptInfo, final RewriteException re) {
if (log.isEnabled()) {
- log.info(new RecompilationEvent(Level.INFO, re, re.getReturnValueNonDestructive()), "RewriteException ", re.getMessageShort());
+ log.info(
+ new RecompilationEvent(
+ Level.INFO,
+ re,
+ re.getReturnValueNonDestructive()),
+ "caught RewriteException ",
+ re.getMessageShort());
+ log.indent();
}
final MethodType type = type();
@@ -799,7 +832,7 @@
logRecompile("Deoptimizing recompilation (up to bytecode) ", fn, ct, effectiveOptInfo.invalidatedProgramPoints);
fn = compiler.compile(fn, serialized ? CompilationPhases.RECOMPILE_SERIALIZED_UPTO_BYTECODE : CompilationPhases.COMPILE_UPTO_BYTECODE);
- log.info("Reusable IR generated");
+ log.fine("Reusable IR generated");
// compile the rest of the function, and install it
log.info("Generating and installing bytecode from reusable IR...");
@@ -815,16 +848,16 @@
compiler.persistClassInfo(cacheKey, normalFn);
}
- log.info("Done.");
-
final boolean canBeDeoptimized = normalFn.canBeDeoptimized();
if (log.isEnabled()) {
- log.info("Recompiled '", fn.getName(), "' (", Debug.id(this), ") ", canBeDeoptimized ? " can still be deoptimized." : " is completely deoptimized.");
+ log.unindent();
+ log.info("Done.");
+
+ log.info("Recompiled '", fn.getName(), "' (", Debug.id(this), ") ", canBeDeoptimized ? "can still be deoptimized." : " is completely deoptimized.");
+ log.finest("Looking up invoker...");
}
- log.info("Looking up invoker...");
-
final MethodHandle newInvoker = effectiveOptInfo.data.lookup(fn);
invoker = newInvoker.asType(type.changeReturnType(newInvoker.type().returnType()));
constructor = null; // Will be regenerated when needed
@@ -870,7 +903,6 @@
private SwitchPoint optimisticAssumptions;
private final DebugLogger log;
- @SuppressWarnings("unused")
OptimismInfo(final RecompilableScriptFunctionData data, final Map<Integer, Type> invalidatedProgramPoints) {
this.data = data;
this.log = data.getLogger();
--- a/nashorn/src/jdk.scripting.nashorn/share/classes/jdk/nashorn/internal/runtime/RecompilableScriptFunctionData.java Wed Nov 12 15:13:08 2014 +0100
+++ b/nashorn/src/jdk.scripting.nashorn/share/classes/jdk/nashorn/internal/runtime/RecompilableScriptFunctionData.java Wed Nov 12 17:19:04 2014 +0100
@@ -26,7 +26,6 @@
package jdk.nashorn.internal.runtime;
import static jdk.nashorn.internal.lookup.Lookup.MH;
-
import java.io.IOException;
import java.lang.invoke.MethodHandle;
import java.lang.invoke.MethodHandles;
@@ -620,20 +619,25 @@
return f;
}
- MethodHandle lookup(final FunctionInitializer fnInit) {
+ private void logLookup(final boolean shouldLog, final MethodType targetType) {
+ if (shouldLog && log.isEnabled()) {
+ log.info("Looking up ", DebugLogger.quote(functionName), " type=", targetType);
+ }
+ }
+
+ private MethodHandle lookup(final FunctionInitializer fnInit, final boolean shouldLog) {
final MethodType type = fnInit.getMethodType();
+ logLookup(shouldLog, type);
return lookupCodeMethod(fnInit.getCode(), type);
}
MethodHandle lookup(final FunctionNode fn) {
final MethodType type = new FunctionSignature(fn).getMethodType();
+ logLookup(true, type);
return lookupCodeMethod(fn.getCompileUnit().getCode(), type);
}
MethodHandle lookupCodeMethod(final Class<?> codeClass, final MethodType targetType) {
- if (log.isEnabled()) {
- log.info("Looking up ", DebugLogger.quote(functionName), " type=", targetType);
- }
return MH.findStatic(LOOKUP, codeClass, functionName, targetType);
}
@@ -649,7 +653,7 @@
if(!code.isEmpty()) {
throw new IllegalStateException(name);
}
- addCode(lookup(initializer), null, null, initializer.getFlags());
+ addCode(lookup(initializer, true), null, null, initializer.getFlags());
}
private CompiledFunction addCode(final MethodHandle target, final Map<Integer, Type> invalidatedProgramPoints,
@@ -671,10 +675,10 @@
*/
private CompiledFunction addCode(final FunctionInitializer fnInit, final MethodType callSiteType) {
if (isVariableArity()) {
- return addCode(lookup(fnInit), fnInit.getInvalidatedProgramPoints(), callSiteType, fnInit.getFlags());
+ return addCode(lookup(fnInit, true), fnInit.getInvalidatedProgramPoints(), callSiteType, fnInit.getFlags());
}
- final MethodHandle handle = lookup(fnInit);
+ final MethodHandle handle = lookup(fnInit, true);
final MethodType fromType = handle.type();
MethodType toType = needsCallee(fromType) ? callSiteType.changeParameterType(0, ScriptFunction.class) : callSiteType.dropParameterTypes(0, 1);
toType = toType.changeReturnType(fromType.returnType());
@@ -699,7 +703,7 @@
toType = toType.dropParameterTypes(fromCount, toCount);
}
- return addCode(lookup(fnInit).asType(toType), fnInit.getInvalidatedProgramPoints(), callSiteType, fnInit.getFlags());
+ return addCode(lookup(fnInit, false).asType(toType), fnInit.getInvalidatedProgramPoints(), callSiteType, fnInit.getFlags());
}
/**