Skip to content

Commit

Permalink
8343449: Nashorn method handle debug logging breaks with log4j-jul
Browse files Browse the repository at this point in the history
Reviewed-by: attila
  • Loading branch information
ppkarwasz authored and szegedi committed Nov 17, 2024
1 parent 2eb88e4 commit 5e78947
Showing 1 changed file with 50 additions and 62 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -58,6 +58,8 @@
*/
public final class MethodHandleFactory {

private static final DebugLogger log = Context.getContext().getLogger(StandardMethodHandleFunctionality.class);

private static final MethodHandles.Lookup PUBLIC_LOOKUP = MethodHandles.publicLookup();
private static final MethodHandles.Lookup LOOKUP = MethodHandles.lookup();

Expand Down Expand Up @@ -100,6 +102,19 @@ public static String stripName(final Object obj) {
return obj.toString();
}

private static final MethodHandle TRACE;
private static final MethodHandle TRACE_RETURN;
private static final MethodHandle TRACE_RETURN_VOID;
static {
try {
TRACE = LOOKUP.findStatic(MethodHandleFactory.class, "traceArgs", MethodType.methodType(void.class, DebugLogger.class, String.class, int.class, Object[].class));
TRACE_RETURN = LOOKUP.findStatic(MethodHandleFactory.class, "traceReturn", MethodType.methodType(Object.class, DebugLogger.class, Object.class));
TRACE_RETURN_VOID = LOOKUP.findStatic(MethodHandleFactory.class, "traceReturnVoid", MethodType.methodType(void.class, DebugLogger.class));
} catch (NoSuchMethodException | IllegalAccessException e) {
throw new LookupException(e);
}
}

private static final MethodHandleFunctionality FUNC = new StandardMethodHandleFunctionality();
private static final boolean PRINT_STACKTRACE = Options.getBooleanProperty("nashorn.methodhandles.debug.stacktrace");

Expand All @@ -111,16 +126,8 @@ public static MethodHandleFunctionality getFunctionality() {
return FUNC;
}

private static final MethodHandle TRACE = FUNC.findStatic(LOOKUP, MethodHandleFactory.class, "traceArgs", MethodType.methodType(void.class, DebugLogger.class, String.class, int.class, Object[].class));
private static final MethodHandle TRACE_RETURN = FUNC.findStatic(LOOKUP, MethodHandleFactory.class, "traceReturn", MethodType.methodType(Object.class, DebugLogger.class, Object.class));
private static final MethodHandle TRACE_RETURN_VOID = FUNC.findStatic(LOOKUP, MethodHandleFactory.class, "traceReturnVoid", MethodType.methodType(void.class, DebugLogger.class));

private static final String VOID_TAG = "[VOID]";

private static void err(final String str) {
Context.getContext().getErr().println(str);
}

/**
* Tracer that is applied before a value is returned from the traced function. It will output the return
* value and its class
Expand All @@ -129,13 +136,11 @@ private static void err(final String str) {
* @return return value unmodified
*/
static Object traceReturn(final DebugLogger logger, final Object value) {
final String str = " return" +
if (logger.isLoggable(TRACE_LEVEL)) {
final String str = " return" +
(VOID_TAG.equals(value) ?
";" :
" " + stripName(value) + "; // [type=" + (value == null ? "null]" : stripName(value.getClass()) + ']'));
if (logger == null) {
err(str);
} else if (logger.isEnabled()) {
";" :
" " + stripName(value) + "; // [type=" + (value == null ? "null]" : stripName(value.getClass()) + ']'));
logger.log(TRACE_LEVEL, str);
}

Expand All @@ -154,48 +159,44 @@ static void traceReturnVoid(final DebugLogger logger) {
* @param args arguments to the function
*/
static void traceArgs(final DebugLogger logger, final String tag, final int paramStart, final Object... args) {
final StringBuilder sb = new StringBuilder();
if (logger.isLoggable(TRACE_LEVEL)) {
final StringBuilder sb = new StringBuilder();

sb.append(tag);
sb.append(tag);

for (int i = paramStart; i < args.length; i++) {
if (i == paramStart) {
sb.append(" => args: ");
}
for (int i = paramStart; i < args.length; i++) {
if (i == paramStart) {
sb.append(" => args: ");
}

sb.append('\'').
append(stripName(argString(args[i]))).
append('\'').
append(' ').
append('[').
append("type=").
append(args[i] == null ? "null" : stripName(args[i].getClass())).
append(']');

sb.append('\'').
append(stripName(argString(args[i]))).
append('\'').
append(' ').
append('[').
append("type=").
append(args[i] == null ? "null" : stripName(args[i].getClass())).
append(']');

if (i + 1 < args.length) {
sb.append(", ");
if (i + 1 < args.length) {
sb.append(", ");
}
}
}

if (logger == null) {
err(sb.toString());
} else {
logger.log(TRACE_LEVEL, sb);
stacktrace(logger);
}
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);
final String st = baos.toString();
if (logger == null) {
err(st);
} else {
if (logger.isLoggable(TRACE_LEVEL)) {
final ByteArrayOutputStream baos = new ByteArrayOutputStream();
final PrintStream ps = new PrintStream(baos);
new Throwable().printStackTrace(ps);
final String st = baos.toString();
logger.log(TRACE_LEVEL, st);
}
}
Expand Down Expand Up @@ -274,15 +275,13 @@ public static MethodHandle addDebugPrintout(final MethodHandle mh, final int par
* @return traced method handle
*/
public static MethodHandle addDebugPrintout(final DebugLogger logger, final Level level, final MethodHandle mh, final int paramStart, final boolean printReturnValue, final Object tag) {
final MethodType type = mh.type();

//if there is no logger, or if it's set to log only coarser events
//than the trace level, skip and return
if (logger == null || !logger.isLoggable(level)) {
return mh;
}

assert TRACE != null;
final MethodType type = mh.type();

MethodHandle trace = MethodHandles.insertArguments(TRACE, 0, logger, tag, paramStart);

Expand Down Expand Up @@ -318,18 +317,12 @@ public static MethodHandle addDebugPrintout(final DebugLogger logger, final Leve
@Logger(name="methodhandles")
private static class StandardMethodHandleFunctionality implements MethodHandleFunctionality, Loggable {

// for bootstrapping reasons, because a lot of static fields use MH for lookups, we
// need to set the logger when the Global object is finished. This means that we don't
// get instrumentation for public static final MethodHandle SOMETHING = MH... in the builtin
// classes, but that doesn't matter, because this is usually not where we want it
private DebugLogger log = DebugLogger.DISABLED_LOGGER;

public StandardMethodHandleFunctionality() {
}

@Override
public DebugLogger initLogger(final Context context) {
return this.log = context.getLogger(this.getClass());
return log;
}

@Override
Expand All @@ -345,12 +338,12 @@ protected static String describe(final Object... data) {
if (d == null) {
sb.append("<null> ");
} else if (isString(d)) {
sb.append(d.toString());
sb.append(d);
sb.append(' ');
} else if (d.getClass().isArray()) {
sb.append("[ ");
for (final Object da : (Object[])d) {
sb.append(describe(new Object[]{ da })).append(' ');
sb.append(describe(da)).append(' ');
}
sb.append("] ");
} else {
Expand All @@ -369,13 +362,8 @@ protected static String describe(final Object... data) {
}

public MethodHandle debug(final MethodHandle master, final String str, final Object... args) {
if (log.isEnabled()) {
if (PRINT_STACKTRACE) {
stacktrace(log);
}
return addDebugPrintout(log, Level.INFO, master, Integer.MAX_VALUE, false, str + ' ' + describe(args));
}
return master;
stacktrace(log);
return addDebugPrintout(log, Level.INFO, master, Integer.MAX_VALUE, false, str + ' ' + describe(args));
}

@Override
Expand Down

3 comments on commit 5e78947

@kangarko
Copy link

@kangarko kangarko commented on 5e78947 Nov 21, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@ppkarwasz this broke our software with the new Velocity update, when will this fix be shipped into a new release, pleasa?

@ppkarwasz
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@kangarko,

I don't know, when a new release of Nashorn is planned, but a workaround for log4j-jul (see apache/logging-log4j2#3125), will be released with Log4j 2.25.0 sometimes next month.

@kangarko
Copy link

@kangarko kangarko commented on 5e78947 Nov 21, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@ppkarwasz Appreciated the swift response! I will compile the latest changes from source until then.

Please sign in to comment.