[epilogue] Log elements based on the most specific available logger (#7317)

Instead of only logging based on the declared type, loggers will be smarter and do instanceof checks to determine what logger should be used.

Note that diamond inheritance may cause unexpected behavior for non-logged classes that implement multiple logged interfaces.
This commit is contained in:
Sam Carlberg
2024-10-31 23:34:41 -04:00
committed by GitHub
parent 0f313c672f
commit fe45265a3a
3 changed files with 348 additions and 10 deletions

View File

@@ -95,7 +95,10 @@ public class AnnotationProcessor extends AbstractProcessor {
// in this list will determine how it gets logged.
m_handlers =
List.of(
new LoggableHandler(processingEnv), // prioritize epilogue logging over Sendable
new LoggableHandler(
processingEnv,
roundEnv.getElementsAnnotatedWith(
Logged.class)), // prioritize epilogue logging over Sendable
new ConfiguredLoggerHandler(
processingEnv, customLoggers), // then customized logging configs
new ArrayHandler(processingEnv),

View File

@@ -5,15 +5,32 @@
package edu.wpi.first.epilogue.processor;
import edu.wpi.first.epilogue.Logged;
import java.util.Collection;
import java.util.Comparator;
import java.util.Set;
import java.util.stream.Collectors;
import javax.annotation.processing.ProcessingEnvironment;
import javax.lang.model.element.Element;
import javax.lang.model.element.ElementKind;
import javax.lang.model.element.ExecutableElement;
import javax.lang.model.element.TypeElement;
import javax.lang.model.element.VariableElement;
import javax.lang.model.type.DeclaredType;
import javax.lang.model.type.TypeKind;
import javax.lang.model.type.TypeMirror;
/** Handles logging for types annotated with the {@link Logged @Logged} annotation. */
public class LoggableHandler extends ElementHandler {
protected LoggableHandler(ProcessingEnvironment processingEnv) {
private final Set<TypeElement> m_loggedTypes;
protected LoggableHandler(
ProcessingEnvironment processingEnv, Collection<? extends Element> loggedTypes) {
super(processingEnv);
m_loggedTypes =
loggedTypes.stream()
.filter(e -> e instanceof TypeElement)
.map(e -> (TypeElement) e)
.collect(Collectors.toSet());
}
@Override
@@ -27,17 +44,165 @@ public class LoggableHandler extends ElementHandler {
@Override
public String logInvocation(Element element) {
TypeMirror dataType = dataType(element);
var reflectedType =
var declaredType =
m_processingEnv
.getElementUtils()
.getTypeElement(m_processingEnv.getTypeUtils().erasure(dataType).toString());
return "Epilogue."
+ StringUtils.loggerFieldName(reflectedType)
+ ".tryUpdate(dataLogger.getSubLogger(\""
+ loggedName(element)
+ "\"), "
+ elementAccess(element)
+ ", Epilogue.getConfig().errorHandler)";
// Get the list of known loggable subtypes of the input type. This will include the input type.
// These are sorted by their distance from the declared type such that "more concrete" types are
// checked first so the instanceof chain doesn't check a really generic type first, even if a
// more specific loggable type could be used instead.
var loggableSubtypes =
m_loggedTypes.stream()
.filter(
l -> m_processingEnv.getTypeUtils().isAssignable(l.asType(), declaredType.asType()))
.sorted(inheritanceComparatorFor(declaredType))
.toList();
int size = loggableSubtypes.size();
// If there are no known loggable subtypes, return just the single logger call
if (size == 1) {
return generateLoggerCall(element, declaredType, elementAccess(element));
}
// Otherwise, generate an if-else chain to compare the element with its known loggable subtypes
// and implementations. A subclass without a @Logged annotation will be logged at runtime using
// the generic logger for whatever the field or method's declared type is.
String varName = cacheVariableName(element);
StringBuilder builder = new StringBuilder();
// Cache the value in a variable so it's only read once
builder.append("var %s = %s;\n".formatted(varName, elementAccess(element)));
for (int i = 0; i < size; i++) {
TypeElement type = loggableSubtypes.get(i);
String part;
if (i == 0) {
// First invocation, generate an "if" statement
part = generateIf(type, element, "if", varName);
} else if (i == size - 1) {
// Final invocation, generate an "else" statement
String loggerCall = generateLoggerCall(element, type, varName);
part =
" else {\n // Base type %s\n %s;\n}"
.formatted(declaredType.getQualifiedName(), loggerCall);
} else {
// Somewhere in the middle, generate an "else if" statement
part = generateIf(type, element, " else if", varName);
}
builder.append(part);
}
return builder.toString();
}
/**
* Generates the name of the cache variable to use for a logged element.
*
* @param element the logged element
* @return the cache variable name
*/
private static String cacheVariableName(Element element) {
// Generate unique names in case a field and a method share the same name
if (element instanceof VariableElement) {
return "$%s".formatted(element.getSimpleName().toString());
} else if (element instanceof ExecutableElement) {
return "_%s".formatted(element.getSimpleName().toString());
} else {
// Generic fallback (shouldn't get here, since only fields and methods are logged)
return element.getSimpleName().toString();
}
}
/**
* Creates a comparator for sorting inheritors of a given type by their distance (farthest first)
* for use in generating if-else instanceof chains. Inheritors at the same distance from the base
* type will be further compared so classes come before interfaces, any any further ties are
* broken alphabetically by fully-qualified type names.
*
* @param declaredType the declared type
* @return the comparator
*/
private Comparator<TypeElement> inheritanceComparatorFor(TypeElement declaredType) {
Comparator<TypeElement> byDistance =
Comparator.comparingInt(
inheritor -> {
return inheritanceDistance(inheritor.asType(), declaredType.asType());
});
return byDistance
.reversed()
.thenComparing(type -> type.getKind() == ElementKind.INTERFACE ? 1 : 0)
.thenComparing(type -> type.getQualifiedName().toString());
}
/**
* Generates an instanceof if or if-else statement that checks the type and logs the element using
* the logger for the given type, if they're compatible.
*
* @param type the type to generate the check for
* @param element the element to be logged
* @param keyword either "if" or " else if"
* @param varName the name of the variable in the "instanceof" check
* @return the if or else-if statement
*/
private String generateIf(TypeElement type, Element element, String keyword, String varName) {
String ref = type.getQualifiedName().toString().replace('.', '_');
String loggerCall = generateLoggerCall(element, type, ref);
return "%s (%s instanceof %s %s) {\n %s;\n}"
.formatted(keyword, varName, type.getQualifiedName(), ref, loggerCall);
}
private String generateLoggerCall(Element element, TypeElement type, String elementReference) {
return ("Epilogue.%s.tryUpdate(dataLogger.getSubLogger(\"%s\"), %s, "
+ "Epilogue.getConfig().errorHandler)")
.formatted(StringUtils.loggerFieldName(type), loggedName(element), elementReference);
}
/**
* Computes the minimum inheritance distance between two types; that is, how many "extends" or
* "implements" clauses are required to get from one to the other.
*
* @param toCheck the type to check
* @param base the base type to check against
* @return the inheritance distance
*/
private int inheritanceDistance(TypeMirror toCheck, TypeMirror base) {
var types = m_processingEnv.getTypeUtils();
if (types.isSameType(toCheck, base)) {
return 0;
}
int distance = 1;
var parent = toCheck;
TypeElement element = m_processingEnv.getElementUtils().getTypeElement(parent.toString());
while (!types.isSameType(parent, base)
&& element.getInterfaces().stream().noneMatch(i -> types.isSameType(i, base))) {
element = m_processingEnv.getElementUtils().getTypeElement(parent.toString());
if (parent.getKind() == TypeKind.NONE) {
// Interface inheritance, there is no superclass
break;
}
parent = element.getSuperclass();
// Handle cases of interface inheritance
distance =
1
+ element.getInterfaces().stream()
.mapToInt(iface -> inheritanceDistance(iface, base))
.min()
.orElse(distance);
}
return distance;
}
}

View File

@@ -1057,6 +1057,176 @@ class AnnotationProcessorTest {
assertLoggerGenerates(source, expectedRootLogger);
}
@Test
void inheritanceOfLoggedTypes() {
String source =
"""
package edu.wpi.first.epilogue;
@Logged
interface IFace {}
@Logged
class Impl1 implements IFace {}
@Logged
class Impl2 implements IFace {}
@Logged
interface I {
int a();
}
@Logged
interface I2 extends I {
int x();
}
@Logged
interface I3 extends I {
int y();
}
@Logged
interface I4 extends I2, I3 {
int z();
}
@Logged
class ConcreteLogged implements I4 {
public int a() { return 0; }
public int x() { return 0; }
public int y() { return 0; }
public int z() { return 0; }
}
class ConcreteNotLogged implements I4 {
public int a() { return 0; }
public int x() { return 0; }
public int y() { return 0; }
public int z() { return 0; }
}
@Logged
public class Example {
IFace asInterface;
Impl1 firstImpl;
Impl2 secondImpl;
I complex;
}
""";
String expectedRootLogger =
"""
package edu.wpi.first.epilogue;
import edu.wpi.first.epilogue.Logged;
import edu.wpi.first.epilogue.Epilogue;
import edu.wpi.first.epilogue.logging.ClassSpecificLogger;
import edu.wpi.first.epilogue.logging.DataLogger;
public class ExampleLogger extends ClassSpecificLogger<Example> {
public ExampleLogger() {
super(Example.class);
}
@Override
public void update(DataLogger dataLogger, Example object) {
if (Epilogue.shouldLog(Logged.Importance.DEBUG)) {
var $asInterface = object.asInterface;
if ($asInterface instanceof edu.wpi.first.epilogue.Impl1 edu_wpi_first_epilogue_Impl1) {
Epilogue.impl1Logger.tryUpdate(dataLogger.getSubLogger("asInterface"), edu_wpi_first_epilogue_Impl1, Epilogue.getConfig().errorHandler);
} else if ($asInterface instanceof edu.wpi.first.epilogue.Impl2 edu_wpi_first_epilogue_Impl2) {
Epilogue.impl2Logger.tryUpdate(dataLogger.getSubLogger("asInterface"), edu_wpi_first_epilogue_Impl2, Epilogue.getConfig().errorHandler);
} else {
// Base type edu.wpi.first.epilogue.IFace
Epilogue.iFaceLogger.tryUpdate(dataLogger.getSubLogger("asInterface"), $asInterface, Epilogue.getConfig().errorHandler);
};
Epilogue.impl1Logger.tryUpdate(dataLogger.getSubLogger("firstImpl"), object.firstImpl, Epilogue.getConfig().errorHandler);
Epilogue.impl2Logger.tryUpdate(dataLogger.getSubLogger("secondImpl"), object.secondImpl, Epilogue.getConfig().errorHandler);
var $complex = object.complex;
if ($complex instanceof edu.wpi.first.epilogue.ConcreteLogged edu_wpi_first_epilogue_ConcreteLogged) {
Epilogue.concreteLoggedLogger.tryUpdate(dataLogger.getSubLogger("complex"), edu_wpi_first_epilogue_ConcreteLogged, Epilogue.getConfig().errorHandler);
} else if ($complex instanceof edu.wpi.first.epilogue.I4 edu_wpi_first_epilogue_I4) {
Epilogue.i4Logger.tryUpdate(dataLogger.getSubLogger("complex"), edu_wpi_first_epilogue_I4, Epilogue.getConfig().errorHandler);
} else if ($complex instanceof edu.wpi.first.epilogue.I2 edu_wpi_first_epilogue_I2) {
Epilogue.i2Logger.tryUpdate(dataLogger.getSubLogger("complex"), edu_wpi_first_epilogue_I2, Epilogue.getConfig().errorHandler);
} else if ($complex instanceof edu.wpi.first.epilogue.I3 edu_wpi_first_epilogue_I3) {
Epilogue.i3Logger.tryUpdate(dataLogger.getSubLogger("complex"), edu_wpi_first_epilogue_I3, Epilogue.getConfig().errorHandler);
} else {
// Base type edu.wpi.first.epilogue.I
Epilogue.iLogger.tryUpdate(dataLogger.getSubLogger("complex"), $complex, Epilogue.getConfig().errorHandler);
};
}
}
}
""";
assertLoggerGenerates(source, expectedRootLogger);
}
@Test
void diamondInheritance() {
String source =
"""
package edu.wpi.first.epilogue;
@Logged
interface I {}
@Logged
interface ExtendingInterface extends I {}
@Logged
class Base implements I {}
/* Not @Logged */
// Diamond inheritance from I (I -> ExtendingInterface -> Inheritor, I -> Base -> Inheritor)
class Inheritor extends Base implements ExtendingInterface {}
@Logged
class Example {
// If this is set to an `Inheritor` instance, it will be logged as a `Base` object rather
// than `ExtendingInterface` or `I`
I theField;
}
""";
String expectedRootLogger =
"""
package edu.wpi.first.epilogue;
import edu.wpi.first.epilogue.Logged;
import edu.wpi.first.epilogue.Epilogue;
import edu.wpi.first.epilogue.logging.ClassSpecificLogger;
import edu.wpi.first.epilogue.logging.DataLogger;
public class ExampleLogger extends ClassSpecificLogger<Example> {
public ExampleLogger() {
super(Example.class);
}
@Override
public void update(DataLogger dataLogger, Example object) {
if (Epilogue.shouldLog(Logged.Importance.DEBUG)) {
var $theField = object.theField;
if ($theField instanceof edu.wpi.first.epilogue.Base edu_wpi_first_epilogue_Base) {
Epilogue.baseLogger.tryUpdate(dataLogger.getSubLogger("theField"), edu_wpi_first_epilogue_Base, Epilogue.getConfig().errorHandler);
} else if ($theField instanceof edu.wpi.first.epilogue.ExtendingInterface edu_wpi_first_epilogue_ExtendingInterface) {
Epilogue.extendingInterfaceLogger.tryUpdate(dataLogger.getSubLogger("theField"), edu_wpi_first_epilogue_ExtendingInterface, Epilogue.getConfig().errorHandler);
} else {
// Base type edu.wpi.first.epilogue.I
Epilogue.iLogger.tryUpdate(dataLogger.getSubLogger("theField"), $theField, Epilogue.getConfig().errorHandler);
};
}
}
}
""";
assertLoggerGenerates(source, expectedRootLogger);
}
@Test
void customLogger() {
String source =