Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fixes location information in JDK14LoggerAdapter #439

Draft
wants to merge 1 commit into
base: master
Choose a base branch
from
Draft

Fixes location information in JDK14LoggerAdapter #439

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
110 changes: 63 additions & 47 deletions slf4j-jdk14/src/main/java/org/slf4j/jul/JDK14LoggerAdapter.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -24,21 +24,22 @@
*/
package org.slf4j.jul;

import java.util.List;
import java.util.logging.Level;
import java.util.logging.LogRecord;

import org.slf4j.Logger;
import org.slf4j.Marker;
import org.slf4j.event.EventConstants;
import org.slf4j.event.KeyValuePair;
import org.slf4j.event.LoggingEvent;
import org.slf4j.helpers.AbstractLogger;
import org.slf4j.helpers.FormattingTuple;
import org.slf4j.helpers.LegacyAbstractLogger;
import org.slf4j.helpers.MessageFormatter;
import org.slf4j.helpers.NormalizedParameters;
import org.slf4j.helpers.SubstituteLogger;
import org.slf4j.spi.DefaultLoggingEventBuilder;
import org.slf4j.spi.LocationAwareLogger;
import org.slf4j.spi.LoggingEventAware;

/**
* A wrapper over {@link java.util.logging.Logger java.util.logging.Logger} in
Expand All @@ -49,7 +50,7 @@
* @author Ceki Gülcü
* @author Peter Royal
*/
public final class JDK14LoggerAdapter extends LegacyAbstractLogger implements LocationAwareLogger {
public final class JDK14LoggerAdapter extends LegacyAbstractLogger implements LocationAwareLogger, LoggingEventAware {

private static final long serialVersionUID = -8053026990503422791L;

Expand Down Expand Up @@ -139,7 +140,8 @@ public boolean isErrorEnabled() {
*/
@Override
protected void handleNormalizedLoggingCall(org.slf4j.event.Level level, Marker marker, String msg, Object[] args, Throwable throwable) {
innerNormalizedLoggingCallHandler(getFullyQualifiedCallerName(), level, marker, msg, args, throwable);
// AbstractLogger is the entry point of all classic API calls
innerNormalizedLoggingCallHandler(SUPER_OF_SUPER, level, marker, msg, args, throwable);
}

private void innerNormalizedLoggingCallHandler(String fqcn, org.slf4j.event.Level level, Marker marker, String msg, Object[] args, Throwable throwable) {
Expand Down Expand Up @@ -180,13 +182,28 @@ public void log(Marker marker, String callerFQCN, int slf4jLevelInt, String mess
*
* @param record The record to update
*/
final private void fillCallerData(String callerFQCN, LogRecord record) {
private void fillCallerData(String callerFQCN, LogRecord record) {
StackTraceElement[] steArray = new Throwable().getStackTrace();
// Find the first stack trace element matching the caller boundary
int selfIndex = NOT_FOUND;
for (int i = 0; i < steArray.length; i++) {
final String className = steArray[i].getClassName();
if (className.equals(callerFQCN)) {
selfIndex = i;
break;
}
}
// Find the first stack trace element after the caller boundary
int found = NOT_FOUND;
for (int i = selfIndex + 1; i < steArray.length; i++) {
final String className = steArray[i].getClassName();
if (!(className.equals(callerFQCN))) {
found = i;
break;
}
}

int furthestIndex = findFurthestIndex(callerFQCN, steArray);

if (furthestIndex != NOT_FOUND) {
int found = furthestIndex+1;
if (found != NOT_FOUND) {
StackTraceElement ste = steArray[found];
// setting the class name has the side effect of setting
// the needToInferCaller variable to false.
Expand All @@ -195,42 +212,9 @@ final private void fillCallerData(String callerFQCN, LogRecord record) {
}
}

// find the furthest index which matches any of the barrier classes
// We assume that the actual caller is at most MAX_SEARCH_DEPTH calls away
private int findFurthestIndex(String callerFQCN, StackTraceElement[] steArray) {

final int maxIndex = Math.min(MAX_SEARCH_DEPTH, steArray.length);
int furthestIndex = NOT_FOUND;

for (int i = 0; i < maxIndex; i++) {
final String className = steArray[i].getClassName();
if (barrierMatch(callerFQCN, className)) {
furthestIndex = i;
}
}
return furthestIndex;
}

static final int MAX_SEARCH_DEPTH = 12;
static String SELF = JDK14LoggerAdapter.class.getName();
static String SELF = JDK14LoggerAdapter.class.getName();

static String SUPER = LegacyAbstractLogger.class.getName();
static String SUPER_OF_SUPER = AbstractLogger.class.getName();
static String SUBSTITUE = SubstituteLogger.class.getName();
static String FLUENT = DefaultLoggingEventBuilder.class.getName();

static String[] BARRIER_CLASSES = new String[] { SUPER_OF_SUPER, SUPER, SELF, SUBSTITUE, FLUENT };

private boolean barrierMatch(String callerFQCN, String candidateClassName) {
if (candidateClassName.equals(callerFQCN))
return true;
for (String barrierClassName : BARRIER_CLASSES) {
if (barrierClassName.equals(candidateClassName)) {
return true;
}
}
return false;
}

private static Level slf4jLevelIntToJULLevel(int levelInt) {
org.slf4j.event.Level slf4jLevel = org.slf4j.event.Level.intToLevel(levelInt);
Expand Down Expand Up @@ -264,12 +248,15 @@ private static Level slf4jLevelToJULLevel(org.slf4j.event.Level slf4jLevel) {
/**
* @since 1.7.15
*/
@Override
public void log(LoggingEvent event) {
// assumes that the invocation is made from a substitute logger
// this assumption might change in the future with the advent of a fluent API
Level julLevel = slf4jLevelToJULLevel(event.getLevel());
if (logger.isLoggable(julLevel)) {
LogRecord record = eventToRecord(event, julLevel);
String callerBoundary = event.getCallerBoundary();
fillCallerData(callerBoundary != null ? callerBoundary : SELF, record);
logger.log(record);
}
}
Expand All @@ -279,16 +266,18 @@ private LogRecord eventToRecord(LoggingEvent event, Level julLevel) {
Object[] arguments = event.getArgumentArray();
FormattingTuple ft = MessageFormatter.arrayFormat(format, arguments);
if (ft.getThrowable() != null && event.getThrowable() != null) {
throw new IllegalArgumentException("both last element in argument array and last argument are of type Throwable");
throw new IllegalArgumentException(
"both last element in argument array and last argument are of type Throwable");
}

Throwable t = event.getThrowable();
if (ft.getThrowable() != null) {
if (t == null && ft.getThrowable() != null) {
t = ft.getThrowable();
throw new IllegalStateException("fix above code");
}

LogRecord record = new LogRecord(julLevel, ft.getMessage());
LogRecord record = new LogRecord(
julLevel,
prependMarkersAndKeyValuePairs(event.getMarkers(), event.getKeyValuePairs(), ft.getMessage()));
record.setLoggerName(event.getLoggerName());
record.setMillis(event.getTimeStamp());
record.setSourceClassName(EventConstants.NA_SUBST);
Expand All @@ -298,4 +287,31 @@ private LogRecord eventToRecord(LoggingEvent event, Level julLevel) {
return record;
}

private String prependMarkersAndKeyValuePairs(
List<Marker> markers, List<KeyValuePair> KeyValuePairs, String message) {
boolean hasMarkers = isNotEmpty(markers);
boolean hasKeyValuePairs = isNotEmpty(KeyValuePairs);
if (!hasMarkers && !hasKeyValuePairs) {
return message;
}
StringBuilder sb = new StringBuilder(message.length());
if (hasMarkers) {
for (Marker marker : markers) {
sb.append(marker).append(' ');
}
}
if (hasKeyValuePairs) {
for (KeyValuePair keyValuePair : KeyValuePairs) {
sb.append(keyValuePair.key)
.append('=')
.append(keyValuePair.value)
.append(' ');
}
}
return sb.append(message).toString();
}

private boolean isNotEmpty(List<?> list) {
return list != null && !list.isEmpty();
}
}
41 changes: 36 additions & 5 deletions slf4j-jdk14/src/test/java/org/slf4j/issue/CallerInfoTest.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -6,7 +6,6 @@
import java.util.List;
import java.util.concurrent.LinkedBlockingQueue;
import java.util.logging.Handler;
import java.util.logging.Level;
import java.util.logging.LogRecord;

import org.junit.After;
Expand All @@ -15,23 +14,25 @@
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.event.EventConstants;
import org.slf4j.event.Level;
import org.slf4j.event.SubstituteLoggingEvent;
import org.slf4j.helpers.SubstituteLogger;
import org.slf4j.helpers.SubstituteServiceProvider;
import org.slf4j.jul.ListHandler;
import org.slf4j.spi.CallerBoundaryAware;
import org.slf4j.spi.LocationAwareLogger;
import org.slf4j.spi.LoggingEventBuilder;

public class CallerInfoTest {
Level oldLevel;
java.util.logging.Level oldLevel;
java.util.logging.Logger root = java.util.logging.Logger.getLogger("");

ListHandler listHandler = new ListHandler();

@Before
public void setUp() throws Exception {
oldLevel = root.getLevel();
root.setLevel(Level.FINE);
root.setLevel(java.util.logging.Level.FINE);
// removeAllHandlers(root);
root.addHandler(listHandler);
}
Expand Down Expand Up @@ -63,6 +64,27 @@ public void testCallerInfo() {
assertEquals(this.getClass().getName(), logRecod.getSourceClassName());
}

/**
* Tests a wrapper that uses the {@link LocationAwareLogger} API.
*
* @see <a href="https://github.com/qos-ch/slf4j/issues/425">#425</a>
*/
@Test
public void testCallerInfoWithAWrapper() {
Logger logger = LoggerFactory.getLogger("bla");
LoggingWrapper wrappedLogger = new LoggingWrapper(logger);

wrappedLogger.logWithLocationAwareApi("hello");

List<LogRecord> recordList = listHandler.recordList;

assertEquals(1, recordList.size());

LogRecord logRecord = recordList.get(0);
assertEquals(this.getClass().getName(), logRecord.getSourceClassName());
assertEquals("testCallerInfoWithAWrapper", logRecord.getSourceMethodName());
}

// Do we preserve location info using fluent API?
// See https://jira.qos.ch/browse/SLF4J-511

Expand All @@ -79,6 +101,9 @@ public void testCallerInfoWithFluentAPI() {
assertEquals(this.getClass().getName(), logRecod.getSourceClassName());
}

/**
* Tests a wrapper that uses the Fluent API.
*/
@Test
public void testCallerInfoWithFluentAPIAndAWrapper() {
Logger logger = LoggerFactory.getLogger("bla");
Expand Down Expand Up @@ -144,15 +169,21 @@ static class LoggingWrapper {
LoggingWrapper(Logger aLogger) {
this.underlyingLogger = aLogger;
}

public void logWithEvent(String msg) {
LoggingEventBuilder lev = underlyingLogger.atInfo();
// setting the caller boundary to LoggingWrapper
if(lev instanceof CallerBoundaryAware) {
if (lev instanceof CallerBoundaryAware) {
// builder is CallerBoundaryAware
((CallerBoundaryAware) lev).setCallerBoundary(LoggingWrapper.class.getName());
}
lev.log(msg);
}
}

public void logWithLocationAwareApi(String msg) {
assertTrue("Logger is an instance of LocationAwareLogger", underlyingLogger instanceof LocationAwareLogger);
((LocationAwareLogger) underlyingLogger)
.log(null, LoggingWrapper.class.getName(), Level.INFO.toInt(), msg, null, null);
}
}
}
11 changes: 11 additions & 0 deletions slf4j-jdk14/src/test/java/org/slf4j/jul/FluentApiInvocationTest.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,7 @@
import org.junit.Test;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MarkerFactory;

public class FluentApiInvocationTest {

Expand Down Expand Up @@ -130,6 +131,16 @@ public void messageWithKeyValuePair() {

}

@Test
public void messageWithMarkers() {
String msg = "Hello world.";
logger.atDebug()
.addMarker(MarkerFactory.getMarker("A"))
.addMarker(MarkerFactory.getMarker("B"))
.log(msg);
assertLogMessage("A B Hello world.", 0);
}

private void assertLogMessage(String expected, int index) {
LogRecord logRecord = listHandler.recordList.get(index);
Assert.assertNotNull(logRecord);
Expand Down
Loading