8063036: Various pretty printing issues with --log=recompile

Wed, 12 Nov 2014 17:19:04 +0100

author
lagergren
date
Wed, 12 Nov 2014 17:19:04 +0100
changeset 1096
568ec2feb228
parent 1095
3dbb4c9ff43c
child 1097
7311b78f9356

8063036: Various pretty printing issues with --log=recompile
Reviewed-by: hannesw, jlaskey

src/jdk/nashorn/internal/runtime/CompiledFunction.java file | annotate | diff | comparison | revisions
src/jdk/nashorn/internal/runtime/RecompilableScriptFunctionData.java file | annotate | diff | comparison | revisions
     1.1 --- a/src/jdk/nashorn/internal/runtime/CompiledFunction.java	Wed Nov 12 14:12:01 2014 +0100
     1.2 +++ b/src/jdk/nashorn/internal/runtime/CompiledFunction.java	Wed Nov 12 17:19:04 2014 +0100
     1.3 @@ -33,9 +33,11 @@
     1.4  import java.lang.invoke.MethodType;
     1.5  import java.lang.invoke.MutableCallSite;
     1.6  import java.lang.invoke.SwitchPoint;
     1.7 +import java.util.ArrayList;
     1.8  import java.util.Collection;
     1.9  import java.util.Collections;
    1.10  import java.util.Iterator;
    1.11 +import java.util.List;
    1.12  import java.util.Map;
    1.13  import java.util.TreeMap;
    1.14  import java.util.function.Supplier;
    1.15 @@ -726,34 +728,58 @@
    1.16       * @param ipp
    1.17       * @return string describing the ipp map
    1.18       */
    1.19 -    private static String toStringInvalidations(final Map<Integer, Type> ipp) {
    1.20 +    private static List<String> toStringInvalidations(final Map<Integer, Type> ipp) {
    1.21          if (ipp == null) {
    1.22 -            return "";
    1.23 +            return Collections.emptyList();
    1.24          }
    1.25  
    1.26 -        final StringBuilder sb = new StringBuilder();
    1.27 +        final List<String> list = new ArrayList<>();
    1.28  
    1.29          for (final Iterator<Map.Entry<Integer, Type>> iter = ipp.entrySet().iterator(); iter.hasNext(); ) {
    1.30              final Map.Entry<Integer, Type> entry = iter.next();
    1.31              final char bct = entry.getValue().getBytecodeStackType();
    1.32 +            final String type;
    1.33  
    1.34 +            switch (entry.getValue().getBytecodeStackType()) {
    1.35 +            case 'A':
    1.36 +                type = "object";
    1.37 +                break;
    1.38 +            case 'I':
    1.39 +                type = "int";
    1.40 +                break;
    1.41 +            case 'J':
    1.42 +                type = "long";
    1.43 +                break;
    1.44 +            case 'D':
    1.45 +                type = "double";
    1.46 +                break;
    1.47 +            default:
    1.48 +                type = String.valueOf(bct);
    1.49 +                break;
    1.50 +            }
    1.51 +
    1.52 +            final StringBuilder sb = new StringBuilder();
    1.53              sb.append('[').
    1.54 +                    append("program point: ").
    1.55                      append(entry.getKey()).
    1.56 -                    append("->").
    1.57 -                    append(bct == 'A' ? 'O' : bct).
    1.58 +                    append(" -> ").
    1.59 +                    append(type).
    1.60                      append(']');
    1.61  
    1.62 -            if (iter.hasNext()) {
    1.63 -                sb.append(' ');
    1.64 -            }
    1.65 +            list.add(sb.toString());
    1.66          }
    1.67  
    1.68 -        return sb.toString();
    1.69 +        return list;
    1.70      }
    1.71  
    1.72      private void logRecompile(final String reason, final FunctionNode fn, final MethodType type, final Map<Integer, Type> ipp) {
    1.73          if (log.isEnabled()) {
    1.74 -            log.info(reason, DebugLogger.quote(fn.getName()), " signature: ", type, " ", toStringInvalidations(ipp));
    1.75 +            log.info(reason, DebugLogger.quote(fn.getName()), " signature: ", type);
    1.76 +            log.indent();
    1.77 +            for (final String str : toStringInvalidations(ipp)) {
    1.78 +                log.fine(str);
    1.79 +            }
    1.80 +            log.unindent();
    1.81          }
    1.82      }
    1.83  
    1.84 @@ -769,7 +795,14 @@
    1.85       */
    1.86      private synchronized MethodHandle handleRewriteException(final OptimismInfo oldOptInfo, final RewriteException re) {
    1.87          if (log.isEnabled()) {
    1.88 -            log.info(new RecompilationEvent(Level.INFO, re, re.getReturnValueNonDestructive()), "RewriteException ", re.getMessageShort());
    1.89 +            log.info(
    1.90 +                    new RecompilationEvent(
    1.91 +                        Level.INFO,
    1.92 +                        re,
    1.93 +                        re.getReturnValueNonDestructive()),
    1.94 +                    "caught RewriteException ",
    1.95 +                    re.getMessageShort());
    1.96 +            log.indent();
    1.97          }
    1.98  
    1.99          final MethodType type = type();
   1.100 @@ -799,7 +832,7 @@
   1.101  
   1.102          logRecompile("Deoptimizing recompilation (up to bytecode) ", fn, ct, effectiveOptInfo.invalidatedProgramPoints);
   1.103          fn = compiler.compile(fn, serialized ? CompilationPhases.RECOMPILE_SERIALIZED_UPTO_BYTECODE : CompilationPhases.COMPILE_UPTO_BYTECODE);
   1.104 -        log.info("Reusable IR generated");
   1.105 +        log.fine("Reusable IR generated");
   1.106  
   1.107          // compile the rest of the function, and install it
   1.108          log.info("Generating and installing bytecode from reusable IR...");
   1.109 @@ -815,16 +848,16 @@
   1.110              compiler.persistClassInfo(cacheKey, normalFn);
   1.111          }
   1.112  
   1.113 -        log.info("Done.");
   1.114 -
   1.115          final boolean canBeDeoptimized = normalFn.canBeDeoptimized();
   1.116  
   1.117          if (log.isEnabled()) {
   1.118 -            log.info("Recompiled '", fn.getName(), "' (", Debug.id(this), ") ", canBeDeoptimized ? " can still be deoptimized." : " is completely deoptimized.");
   1.119 +            log.unindent();
   1.120 +            log.info("Done.");
   1.121 +
   1.122 +            log.info("Recompiled '", fn.getName(), "' (", Debug.id(this), ") ", canBeDeoptimized ? "can still be deoptimized." : " is completely deoptimized.");
   1.123 +            log.finest("Looking up invoker...");
   1.124          }
   1.125  
   1.126 -        log.info("Looking up invoker...");
   1.127 -
   1.128          final MethodHandle newInvoker = effectiveOptInfo.data.lookup(fn);
   1.129          invoker     = newInvoker.asType(type.changeReturnType(newInvoker.type().returnType()));
   1.130          constructor = null; // Will be regenerated when needed
   1.131 @@ -870,7 +903,6 @@
   1.132          private SwitchPoint optimisticAssumptions;
   1.133          private final DebugLogger log;
   1.134  
   1.135 -        @SuppressWarnings("unused")
   1.136          OptimismInfo(final RecompilableScriptFunctionData data, final Map<Integer, Type> invalidatedProgramPoints) {
   1.137              this.data = data;
   1.138              this.log  = data.getLogger();
     2.1 --- a/src/jdk/nashorn/internal/runtime/RecompilableScriptFunctionData.java	Wed Nov 12 14:12:01 2014 +0100
     2.2 +++ b/src/jdk/nashorn/internal/runtime/RecompilableScriptFunctionData.java	Wed Nov 12 17:19:04 2014 +0100
     2.3 @@ -26,7 +26,6 @@
     2.4  package jdk.nashorn.internal.runtime;
     2.5  
     2.6  import static jdk.nashorn.internal.lookup.Lookup.MH;
     2.7 -
     2.8  import java.io.IOException;
     2.9  import java.lang.invoke.MethodHandle;
    2.10  import java.lang.invoke.MethodHandles;
    2.11 @@ -620,20 +619,25 @@
    2.12          return f;
    2.13      }
    2.14  
    2.15 -    MethodHandle lookup(final FunctionInitializer fnInit) {
    2.16 +    private void logLookup(final boolean shouldLog, final MethodType targetType) {
    2.17 +        if (shouldLog && log.isEnabled()) {
    2.18 +            log.info("Looking up ", DebugLogger.quote(functionName), " type=", targetType);
    2.19 +        }
    2.20 +    }
    2.21 +
    2.22 +    private MethodHandle lookup(final FunctionInitializer fnInit, final boolean shouldLog) {
    2.23          final MethodType type = fnInit.getMethodType();
    2.24 +        logLookup(shouldLog, type);
    2.25          return lookupCodeMethod(fnInit.getCode(), type);
    2.26      }
    2.27  
    2.28      MethodHandle lookup(final FunctionNode fn) {
    2.29          final MethodType type = new FunctionSignature(fn).getMethodType();
    2.30 +        logLookup(true, type);
    2.31          return lookupCodeMethod(fn.getCompileUnit().getCode(), type);
    2.32      }
    2.33  
    2.34      MethodHandle lookupCodeMethod(final Class<?> codeClass, final MethodType targetType) {
    2.35 -        if (log.isEnabled()) {
    2.36 -            log.info("Looking up ", DebugLogger.quote(functionName), " type=", targetType);
    2.37 -        }
    2.38          return MH.findStatic(LOOKUP, codeClass, functionName, targetType);
    2.39      }
    2.40  
    2.41 @@ -649,7 +653,7 @@
    2.42          if(!code.isEmpty()) {
    2.43              throw new IllegalStateException(name);
    2.44          }
    2.45 -        addCode(lookup(initializer), null, null, initializer.getFlags());
    2.46 +        addCode(lookup(initializer, true), null, null, initializer.getFlags());
    2.47      }
    2.48  
    2.49      private CompiledFunction addCode(final MethodHandle target, final Map<Integer, Type> invalidatedProgramPoints,
    2.50 @@ -671,10 +675,10 @@
    2.51       */
    2.52      private CompiledFunction addCode(final FunctionInitializer fnInit, final MethodType callSiteType) {
    2.53          if (isVariableArity()) {
    2.54 -            return addCode(lookup(fnInit), fnInit.getInvalidatedProgramPoints(), callSiteType, fnInit.getFlags());
    2.55 +            return addCode(lookup(fnInit, true), fnInit.getInvalidatedProgramPoints(), callSiteType, fnInit.getFlags());
    2.56          }
    2.57  
    2.58 -        final MethodHandle handle = lookup(fnInit);
    2.59 +        final MethodHandle handle = lookup(fnInit, true);
    2.60          final MethodType fromType = handle.type();
    2.61          MethodType toType = needsCallee(fromType) ? callSiteType.changeParameterType(0, ScriptFunction.class) : callSiteType.dropParameterTypes(0, 1);
    2.62          toType = toType.changeReturnType(fromType.returnType());
    2.63 @@ -699,7 +703,7 @@
    2.64              toType = toType.dropParameterTypes(fromCount, toCount);
    2.65          }
    2.66  
    2.67 -        return addCode(lookup(fnInit).asType(toType), fnInit.getInvalidatedProgramPoints(), callSiteType, fnInit.getFlags());
    2.68 +        return addCode(lookup(fnInit, false).asType(toType), fnInit.getInvalidatedProgramPoints(), callSiteType, fnInit.getFlags());
    2.69      }
    2.70  
    2.71      /**

mercurial