stan/jdk-24
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

8005788: Loggers and their corresponding system properties not working correctly

Browse Source 
1-1 mapping now maintained. Used Context err instead of System.err in several places (after bootstrapping Context). Problematic closing of err stream replaced by @SuppressWarnings("resource")

Reviewed-by: jlaskey, sundar
This commit is contained in:
Marcus Lagergren 2013-01-08 09:59:28 +01:00
parent b501e8fdc4
commit 51ceb76240
13 changed files with 192 additions and 167 deletions

0
nashorn/bin/fixorphantests.sh Normal file → Executable file

0
nashorn/bin/fixwhitespace.sh Normal file → Executable file

34
nashorn/src/jdk/nashorn/internal/ir/Symbol.java

@ -27,6 +27,7 @@ package jdk.nashorn.internal.ir;
import java.io.PrintWriter;
import jdk.nashorn.internal.codegen.types.Type;
import jdk.nashorn.internal.runtime.Context;
import jdk.nashorn.internal.runtime.options.Options;
/**
@ -549,12 +550,7 @@ public final class Symbol implements Comparable<Symbol> {
* @param slot valid bytecode slot, or -1 if not available
*/
public void setSlot(final int slot) {
if (TRACE_SYMBOL != null) {
if (TRACE_SYMBOL.equals(name)) {
System.err.println(name + " gets slot " + slot);
new Throwable().printStackTrace();
}
}
trace("SET SLOT " + slot);
this.slot = slot;
}
@ -574,18 +570,7 @@ public final class Symbol implements Comparable<Symbol> {
* @param type the type
*/
public void setType(final Type type) {
if (TRACE_SYMBOL == null) {
setTypeOverride(Type.widest(this.type, type));
} else {
final boolean check = TRACE_SYMBOL.equals(getName());
final Type from = this.type;
setTypeOverride(Type.widest(this.type, type));
if (check) {
System.err.println(getName() + " " + from + "=>" + type + " == " + this.type);
new Throwable().printStackTrace();
}
}
setTypeOverride(Type.widest(this.type, type));
}
/**
@ -596,7 +581,11 @@ public final class Symbol implements Comparable<Symbol> {
* @param type the type
*/
public void setTypeOverride(final Type type) {
this.type = type;
final Type old = this.type;
if (old != type) {
trace("TYPE CHANGE: " + old + "=>" + type + " == " + type);
this.type = type;
}
}
/**
@ -607,4 +596,11 @@ public final class Symbol implements Comparable<Symbol> {
public boolean isTopLevel() {
return block instanceof FunctionNode && ((FunctionNode) block).isScript();
}
private void trace(final String desc) {
if (TRACE_SYMBOL != null && TRACE_SYMBOL.equals(name)) {
Context.err("SYMBOL: '" + name + "' " + desc);
new Throwable().printStackTrace(Context.getContext().getErr());
}
}
}

9
nashorn/src/jdk/nashorn/internal/objects/NativeDebug.java

@ -27,12 +27,13 @@ package jdk.nashorn.internal.objects;
import static jdk.nashorn.internal.runtime.ScriptRuntime.UNDEFINED;
import java.io.PrintStream;
import java.io.PrintWriter;
import java.util.Objects;
import jdk.nashorn.internal.objects.annotations.Attribute;
import jdk.nashorn.internal.objects.annotations.Function;
import jdk.nashorn.internal.objects.annotations.ScriptClass;
import jdk.nashorn.internal.objects.annotations.Where;
import jdk.nashorn.internal.runtime.Context;
import jdk.nashorn.internal.runtime.PropertyListenerManager;
import jdk.nashorn.internal.runtime.PropertyMap;
import jdk.nashorn.internal.runtime.ScriptFunction;
@ -248,9 +249,11 @@ public class NativeDebug extends ScriptObject {
* @param self self reference
* @return undefined
*/
@SuppressWarnings("resource")
@Function(attributes = Attribute.NOT_ENUMERABLE, where = Where.CONSTRUCTOR)
public static Object dumpCounters(final Object self) {
final PrintStream out = System.err;
final PrintWriter out = Context.getContext().getErr();
out.println("ScriptObject count " + ScriptObject.getCount());
out.println("Scope count " + ScriptObject.getScopeCount());
out.println("ScriptObject listeners added " + PropertyListenerManager.getListenersAdded());
@ -268,7 +271,9 @@ public class NativeDebug extends ScriptObject {
out.println("Callsite count " + LinkerCallSite.getCount());
out.println("Callsite misses " + LinkerCallSite.getMissCount());
out.println("Callsite misses by site at " + LinkerCallSite.getMissSamplingPercentage() + "%");
LinkerCallSite.getMissCounts(out);
return UNDEFINED;
}
}

28
nashorn/src/jdk/nashorn/internal/runtime/Context.java

@ -71,6 +71,12 @@ public final class Context {
}
};
/**
* Get the error stream if applicable and initialized, otherwise stderr
* Usually this is the error stream given the context, but for testing and
* certain bootstrapping situations we need a default stream
*/
/**
* Return the current global scope
* @return current global scope
@ -119,20 +125,14 @@ public final class Context {
* @param str text to write
* @param crlf write a carriage return/new line after text
*/
@SuppressWarnings("resource")
public static void err(final String str, final boolean crlf) {
try (final PrintWriter err = Context.getContext().getErr()) {
if (err != null) {
if (crlf) {
err.println(str);
} else {
err.print(str);
}
final PrintWriter err = Context.getContext().getErr();
if (err != null) {
if (crlf) {
err.println(str);
} else {
if (crlf) {
System.err.println(str);
} else {
System.err.println();
}
err.print(str);
}
}
}
@ -680,13 +680,11 @@ public final class Context {
* Hook to print stack trace for a {@link Throwable} that occurred during
* execution
*
* TODO: use Context.err
* .
* @param t throwable for which to dump stack
*/
public static void printStackTrace(final Throwable t) {
if (Context.DEBUG) {
t.printStackTrace();
t.printStackTrace(Context.getContext().getErr());
}
}

8
nashorn/src/jdk/nashorn/internal/runtime/DebugLogger.java

@ -59,8 +59,12 @@ public class DebugLogger {
* @param property system property activating the logger on {@code info} level
*/
public DebugLogger(final String loggerName, final String property) {
this.logger = Logging.getLogger(loggerName);
this.isEnabled = logger.getLevel() != Level.OFF || (property != null && Options.getBooleanProperty(property));
if (property != null && Options.getBooleanProperty(property)) {
this.logger = Logging.getOrCreateLogger(loggerName, Level.INFO);
} else {
this.logger = Logging.getLogger(loggerName);
}
this.isEnabled = logger.getLevel() != Level.OFF;
}
/**

5
nashorn/src/jdk/nashorn/internal/runtime/ECMAException.java

@ -181,11 +181,10 @@ public final class ECMAException extends NashornException {
*/
public static Object printStackTrace(final ScriptObject errObj) {
final Object exception = getException(errObj);
//TODO context err instead of System.err default
if (exception instanceof Throwable) {
((Throwable)exception).printStackTrace();
((Throwable)exception).printStackTrace(Context.getContext().getErr());
} else {
System.err.println("<stack trace not available>");
Context.err("<stack trace not available>");
}
return UNDEFINED;
}

2
nashorn/src/jdk/nashorn/internal/runtime/ErrorManager.java

@ -55,7 +55,7 @@ public class ErrorManager {
* Constructor
*/
public ErrorManager() {
this(new PrintWriter(System.err, true));
this(new PrintWriter(System.err, true)); //bootstrapping, context may not be initialized
}
/**

86
nashorn/src/jdk/nashorn/internal/runtime/Logging.java

@ -72,17 +72,7 @@ public class Logging {
* Get a logger for a given class, generating a logger name based on the
* class name
*
* @param clazz the class
* @return the logger
*/
public static Logger getLogger0(final Class<?> clazz) {
return Logging.getLogger(Logging.lastPart(clazz.getPackage().getName()));
}
/**
* Get a logger for a given name
*
* @param name the name to use as key
* @param name the name to use as key for the logger
* @return the logger
*/
public static Logger getLogger(final String name) {
@ -93,6 +83,23 @@ public class Logging {
return Logging.disabledLogger;
}
/**
* Get a logger for a given name or create it if not already there, typically
* used for mapping system properties to loggers
*
* @param name the name to use as key
* @param level log lever to reset existing logger with, or create new logger with
* @return the logger
*/
public static Logger getOrCreateLogger(final String name, final Level level) {
final Logger logger = Logging.loggers.get(name);
if (logger == null) {
return instantiateLogger(name, level);
}
logger.setLevel(level);
return logger;
}
/**
* Initialization function that is called to instantiate the logging system. It takes
* logger names (keys) and logging labels respectively
@ -114,32 +121,7 @@ public class Logging {
}
final String name = Logging.lastPart(key);
final Logger logger = java.util.logging.Logger.getLogger(name);
for (final Handler h : logger.getHandlers()) {
logger.removeHandler(h);
}
logger.setLevel(level);
logger.setUseParentHandlers(false);
final Handler c = new ConsoleHandler();
c.setFormatter(new Formatter() {
@Override
public String format(final LogRecord record) {
final StringBuilder sb = new StringBuilder();
sb.append('[')
.append(record.getLoggerName())
.append("] ")
.append(record.getMessage())
.append('\n');
return sb.toString();
}
});
logger.addHandler(c);
c.setLevel(level);
final Logger logger = instantiateLogger(name, level);
Logging.loggers.put(name, logger);
}
@ -148,4 +130,34 @@ public class Logging {
}
}
private static Logger instantiateLogger(final String name, final Level level) {
final Logger logger = java.util.logging.Logger.getLogger(name);
for (final Handler h : logger.getHandlers()) {
logger.removeHandler(h);
}
logger.setLevel(level);
logger.setUseParentHandlers(false);
final Handler c = new ConsoleHandler();
c.setFormatter(new Formatter() {
@Override
public String format(final LogRecord record) {
final StringBuilder sb = new StringBuilder();
sb.append('[')
.append(record.getLoggerName())
.append("] ")
.append(record.getMessage())
.append('\n');
return sb.toString();
}
});
logger.addHandler(c);
c.setLevel(level);
return logger;
}
}

48
nashorn/src/jdk/nashorn/internal/runtime/linker/LinkerCallSite.java

@ -29,8 +29,7 @@ import static jdk.nashorn.internal.runtime.linker.Lookup.MH;
import java.io.FileNotFoundException;
import java.io.FileOutputStream;
import java.io.OutputStream;
import java.io.PrintStream;
import java.io.PrintWriter;
import java.lang.invoke.MethodHandle;
import java.lang.invoke.MethodHandles;
import java.lang.invoke.MethodType;
@ -275,24 +274,35 @@ public class LinkerCallSite extends ChainedCallSite {
}
static class ProfileDumper implements Runnable {
@SuppressWarnings("resource")
@Override
public void run() {
OutputStream out;
PrintWriter out = null;
boolean fileOutput = false;
try {
out = new FileOutputStream(PROFILEFILE);
} catch (final FileNotFoundException e) {
out = new PrintStream(System.err); //TODO abstraction break- why is this hard coded to System.err when everything else uses the context
}
try (PrintStream stream = new PrintStream(out)) {
int index = 0;
for (final ProfilingLinkerCallSite callSite : profileCallSites) {
stream.println("" + (index++) + '\t' +
callSite.getDescriptor().getName() + '\t' +
callSite.totalTime + '\t' +
callSite.hitCount);
try {
out = new PrintWriter(new FileOutputStream(PROFILEFILE));
fileOutput = true;
} catch (final FileNotFoundException e) {
out = Context.getContext().getErr();
}
dump(out);
} finally {
if (out != null && fileOutput) {
out.close();
}
}
}
private static void dump(final PrintWriter out) {
int index = 0;
for (final ProfilingLinkerCallSite callSite : profileCallSites) {
out.println("" + (index++) + '\t' +
callSite.getDescriptor().getName() + '\t' +
callSite.totalTime + '\t' +
callSite.hitCount);
}
}
}
@ -307,11 +317,7 @@ public class LinkerCallSite extends ChainedCallSite {
private static final MethodHandle TRACEVOID = findOwnMH("traceVoid", void.class, MethodHandle.class, Object[].class);
private static final MethodHandle TRACEMISS = findOwnMH("traceMiss", void.class, Object[].class);
private static final PrintStream out = System.err; //TODO abstraction break- why is this hard coded to System.err when everything else uses the context
/*
* Constructor
*/
private static final PrintWriter out = Context.getContext().getErr();
TracingLinkerCallSite(final NashornCallSiteDescriptor desc) {
super(desc);
@ -522,7 +528,7 @@ public class LinkerCallSite extends ChainedCallSite {
* Dump the miss counts collected so far to a given output stream
* @param out print stream
*/
public static void getMissCounts(final PrintStream out) {
public static void getMissCounts(final PrintWriter out) {
final ArrayList<Entry<String, AtomicInteger>> entries = new ArrayList<>(missCounts.entrySet());
Collections.sort(entries, new Comparator<Map.Entry<String, AtomicInteger>>() {

93
nashorn/src/jdk/nashorn/internal/runtime/linker/MethodHandleFactory.java

@ -25,6 +25,13 @@
package jdk.nashorn.internal.runtime.linker;
import jdk.nashorn.internal.runtime.ConsString;
import jdk.nashorn.internal.runtime.Debug;
import jdk.nashorn.internal.runtime.DebugLogger;
import jdk.nashorn.internal.runtime.ScriptObject;
import jdk.nashorn.internal.runtime.options.Options;
import java.io.ByteArrayOutputStream;
import java.io.PrintStream;
import java.lang.invoke.MethodHandle;
import java.lang.invoke.MethodHandles;
@ -35,29 +42,23 @@ import java.util.ArrayList;
import java.util.Arrays;
import java.util.List;
import java.util.logging.Level;
import jdk.nashorn.internal.runtime.ConsString;
import jdk.nashorn.internal.runtime.Debug;
import jdk.nashorn.internal.runtime.DebugLogger;
import jdk.nashorn.internal.runtime.ScriptObject;
import jdk.nashorn.internal.runtime.options.Options;
/**
* This class is abstraction for all method handle, switchpoint and method type
* operations. This enables the functionality interface to be subclassed and
* instrumented, as it has been proven vital to keep the number of method
* intrumensted, as it has been proven vital to keep the number of method
* handles in the system down.
* <p>
*
* All operations of the above type should go through this class, and not
* directly into java.lang.invoke
*
*/
public final class MethodHandleFactory {
private static final MethodHandles.Lookup PUBLIC_LOOKUP = MethodHandles.publicLookup();
private static final MethodHandles.Lookup LOOKUP = MethodHandles.lookup();
private static PrintStream ERR = System.err;
private static final Level TRACE_LEVEL = Level.FINEST;
private static final Level TRACE_LEVEL = Level.INFO;
private MethodHandleFactory() {
}
@ -97,15 +98,26 @@ public final class MethodHandleFactory {
}
private static final MethodHandleFunctionality STANDARD = new StandardMethodHandleFunctionality();
private static final MethodHandleFunctionality FUNC =
Options.getBooleanProperty("nashorn.methodhandles.debug") ?
(Options.getStringProperty("nashorn.methodhandles.debug","").equals("create") ?
new TraceCreateMethodHandleFunctionality() :
new TraceMethodHandleFunctionality())
: STANDARD;
private static final MethodHandleFunctionality FUNC;
private static final String DEBUG_PROPERTY = "nashorn.methodhandles.debug";
private static final DebugLogger LOG = new DebugLogger("methodhandles", DEBUG_PROPERTY);
static {
if (LOG.isEnabled() || Options.getBooleanProperty(DEBUG_PROPERTY)) {
if (Options.getStringProperty(DEBUG_PROPERTY, "").equals("create")) {
FUNC = new TraceCreateMethodHandleFunctionality();
} else {
FUNC = new TraceMethodHandleFunctionality();
}
} else {
FUNC = STANDARD;
}
}
private static final boolean PRINT_STACKTRACE = Options.getBooleanProperty("nashorn.methodhandles.debug.stacktrace");
/**
* Return the method handle functionality used for all method handle operations
* @return a method handle functionality implementation
@ -126,11 +138,7 @@ public final class MethodHandleFactory {
*/
static Object traceReturn(final DebugLogger logger, final Object value) {
final String str = "\treturn: " + stripName(value) + " [type=" + (value == null ? "null" : stripName(value.getClass()) + ']');
if (logger != null) {
logger.log(str, TRACE_LEVEL);
} else {
ERR.println(str);
}
logger.log(str, TRACE_LEVEL);
return value;
}
@ -165,14 +173,19 @@ public final class MethodHandleFactory {
}
}
if (logger != null) {
logger.log(sb.toString(), TRACE_LEVEL);
} else {
ERR.print(sb);
if (PRINT_STACKTRACE) {
new Throwable().printStackTrace(ERR);
}
assert logger != null;
logger.log(sb.toString(), TRACE_LEVEL);
stacktrace(logger);
}
private static void stacktrace(final DebugLogger logger) {
if (!PRINT_STACKTRACE) {
return;
}
final ByteArrayOutputStream baos = new ByteArrayOutputStream();
final PrintStream ps = new PrintStream(baos);
new Throwable().printStackTrace(ps);
logger.log(baos.toString(), TRACE_LEVEL);
}
private static String argString(final Object arg) {
@ -198,18 +211,6 @@ public final class MethodHandleFactory {
return arg.toString();
}
/**
* Add a debug printout to a method handle, tracing parameters and return values. Output
* will be written to stderr.
*
* @param mh method handle to trace
* @param tag start of trace message
* @return traced method handle
*/
public static MethodHandle addDebugPrintout0(final MethodHandle mh, final Object tag) {
return addDebugPrintout(null, mh, 0, true, tag);
}
/**
* Add a debug printout to a method handle, tracing parameters and return values
*
@ -240,6 +241,7 @@ public final class MethodHandleFactory {
return mh;
}
assert logger != null;
assert TRACE != null;
MethodHandle trace = MethodHandles.insertArguments(TRACE, 0, logger, tag, paramStart);
@ -263,7 +265,7 @@ public final class MethodHandleFactory {
}
/**
* The standard class that marshals all method handle operations to the java.lang.invoke
* The standard class that marshalls all method handle operations to the java.lang.invoke
* package. This exists only so that it can be subclassed and method handles created from
* Nashorn made possible to instrument.
*
@ -464,7 +466,7 @@ public final class MethodHandleFactory {
}
public MethodHandle debug(final MethodHandle master, final String str, final Object... args) {
return addDebugPrintout(null, master, Integer.MAX_VALUE, false, str + ' ' + describe(args));
return addDebugPrintout(LOG, master, Integer.MAX_VALUE, false, str + ' ' + describe(args));
}
@Override
@ -602,7 +604,7 @@ public final class MethodHandleFactory {
@Override
public SwitchPoint createSwitchPoint() {
final SwitchPoint sp = super.createSwitchPoint();
ERR.println("createSwitchPoint " + sp);
LOG.log("createSwitchPoint " + sp, TRACE_LEVEL);
return sp;
}
@ -615,7 +617,7 @@ public final class MethodHandleFactory {
@Override
public MethodType type(final Class<?> returnType, final Class<?>... paramTypes) {
final MethodType mt = super.type(returnType, paramTypes);
ERR.println("methodType " + returnType + ' ' + Arrays.toString(paramTypes) + ' ' + mt);
LOG.log("methodType " + returnType + ' ' + Arrays.toString(paramTypes) + ' ' + mt, TRACE_LEVEL);
return mt;
}
}
@ -626,7 +628,8 @@ public final class MethodHandleFactory {
private static class TraceCreateMethodHandleFunctionality extends TraceMethodHandleFunctionality {
@Override
public MethodHandle debug(final MethodHandle master, final String str, final Object... args) {
ERR.println(str + ' ' + describe(args));
LOG.log(str + ' ' + describe(args), TRACE_LEVEL);
stacktrace(LOG);
return master;
}
}

44
nashorn/src/jdk/nashorn/internal/runtime/options/Options.java

@ -44,19 +44,19 @@ import java.util.StringTokenizer;
import java.util.TimeZone;
import java.util.TreeMap;
import java.util.TreeSet;
import jdk.nashorn.internal.runtime.Logging;
import jdk.nashorn.internal.runtime.QuotedStringTokenizer;
/**
* Manages global runtime options.
*
*/
public final class Options {
/** Resource tag. */
private final String resource;
/** Error writer. */
private final PrintWriter errors;
private final PrintWriter err;
/** File list. */
private final List<String> files;
@ -68,14 +68,25 @@ public final class Options {
private final TreeMap<String, Option<?>> options;
/**
* Constructor.
* Constructor
*
* Options will use System.err as the output stream for any errors
*
* @param resource resource prefix for options e.g. "nashorn"
* @param errors error stream for reporting parse errors
*/
public Options(final String resource, final PrintWriter errors) {
public Options(final String resource) {
this(resource, new PrintWriter(System.err, true));
}
/**
* Constructor
*
* @param resource resource prefix for options e.g. "nashorn"
* @param err error stream for reporting parse errors
*/
public Options(final String resource, final PrintWriter err) {
this.resource = resource;
this.errors = errors;
this.err = err;
this.files = new ArrayList<>();
this.arguments = new ArrayList<>();
this.options = new TreeMap<>();
@ -88,21 +99,12 @@ public final class Options {
if (v != null) {
set(t.getKey(), createOption(t, v));
} else if (t.getDefaultValue() != null) {
set(t.getKey(), createOption(t, t.getDefaultValue()));
set(t.getKey(), createOption(t, t.getDefaultValue()));
}
}
}
}
/**
* Constructor
*
* @param resource e.g. "nashorn"
*/
public Options(final String resource) {
this(resource, new PrintWriter(System.err, true));
}
/**
* Get the resource for this Options set, e.g. "nashorn"
* @return the resource
@ -343,17 +345,17 @@ public final class Options {
// display extended help information
displayHelp(true);
} else {
errors.println(((IllegalOptionException)e).getTemplate());
err.println(((IllegalOptionException)e).getTemplate());
}
return;
}
if (e != null && e.getMessage() != null) {
errors.println(getMsg("option.error.invalid.option",
err.println(getMsg("option.error.invalid.option",
e.getMessage(),
helpOptionTemplate.getShortName(),
helpOptionTemplate.getName()));
errors.println();
err.println();
return;
}
@ -368,8 +370,8 @@ public final class Options {
public void displayHelp(final boolean extended) {
for (final OptionTemplate t : Options.validOptions) {
if ((extended || !t.isUndocumented()) && t.getResource().equals(resource)) {
errors.println(t);
errors.println();
err.println(t);
err.println();
}
}
}

2
nashorn/src/jdk/nashorn/tools/Shell.java

@ -114,7 +114,7 @@ public class Shell {
try {
System.exit(main(System.in, System.out, System.err, args));
} catch (final IOException e) {
System.err.println(e);
System.err.println(e); //bootstrapping, Context.err may not exist
System.exit(IO_ERROR);
}
}