Skip to content

Commit

Permalink
[GR-57651] Backport to 23.1: Reduce logging overhead in debug info ge…
Browse files Browse the repository at this point in the history 
…nerator.

PullRequest: graal/17424
  • Loading branch information
@fniephaus @marwan-hallaoui
fniephaus authored and marwan-hallaoui committed Aug 30, 2024
2 parents ae0bc06 + b851a8b commit bd8874b
Show file tree
Hide file tree
Showing 9 changed files with 48 additions and 29 deletions.
2 changes: 1 addition & 1 deletion docs/reference-manual/native-image/BuildOutput.md
View file
Original file line number Diff line number Diff line change
Expand Up @@ -39,7 +39,7 @@ GraalVM Native Image: Generating 'helloworld' (executable)...
[4/8] Parsing methods... [*] (0.6s @ 0.75GB)
[5/8] Inlining methods... [***] (0.3s @ 0.32GB)
[6/8] Compiling methods... [**] (3.7s @ 0.60GB)
[7/8] Layouting methods... [*] (0.8s @ 0.83GB)
[7/8] Laying out methods... [*] (0.8s @ 0.83GB)
[8/8] Creating image... [**] (3.1s @ 0.58GB)
5.32MB (24.22%) for code area: 8,702 compilation units
7.03MB (32.02%) for image heap: 93,301 objects and 5 resources
Expand Down
4 changes: 3 additions & 1 deletion ...ratevm/src/com.oracle.objectfile/src/com/oracle/objectfile/debugentry/ArrayTypeEntry.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -56,7 +56,9 @@ public void addDebugInfo(DebugInfoBase debugInfoBase, DebugTypeInfo debugTypeInf
this.lengthOffset = debugArrayTypeInfo.lengthOffset();
/* Add details of fields and field types */
debugArrayTypeInfo.fieldInfoProvider().forEach(debugFieldInfo -> this.processField(debugFieldInfo, debugInfoBase, debugContext));
debugContext.log("typename %s element type %s base size %d length offset %d%n", typeName, this.elementType.getTypeName(), baseSize, lengthOffset);
if (debugContext.isLogEnabled()) {
debugContext.log("typename %s element type %s base size %d length offset %d%n", typeName, this.elementType.getTypeName(), baseSize, lengthOffset);
}
}

public TypeEntry getElementType() {
Expand Down
21 changes: 10 additions & 11 deletions substratevm/src/com.oracle.objectfile/src/com/oracle/objectfile/debugentry/ClassEntry.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -132,13 +132,9 @@ public void addDebugInfo(DebugInfoBase debugInfoBase, DebugTypeInfo debugTypeInf
DebugInstanceTypeInfo debugInstanceTypeInfo = (DebugInstanceTypeInfo) debugTypeInfo;
/* Add details of super and interface classes */
ResolvedJavaType superType = debugInstanceTypeInfo.superClass();
String superName;
if (superType != null) {
superName = superType.toJavaName();
} else {
superName = "";
if (debugContext.isLogEnabled()) {
debugContext.log("typename %s adding super %s%n", typeName, superType != null ? superType.toJavaName() : "");
}
debugContext.log("typename %s adding super %s%n", typeName, superName);
if (superType != null) {
this.superClass = debugInfoBase.lookupClassEntry(superType);
}
Expand Down Expand Up @@ -250,8 +246,9 @@ public Stream<CompiledMethodEntry> compiledEntries() {
}

protected void processInterface(ResolvedJavaType interfaceType, DebugInfoBase debugInfoBase, DebugContext debugContext) {
String interfaceName = interfaceType.toJavaName();
debugContext.log("typename %s adding interface %s%n", typeName, interfaceName);
if (debugContext.isLogEnabled()) {
debugContext.log("typename %s adding interface %s%n", typeName, interfaceType.toJavaName());
}
ClassEntry entry = debugInfoBase.lookupClassEntry(interfaceType);
assert entry instanceof InterfaceClassEntry || (entry instanceof ForeignTypeEntry && this instanceof ForeignTypeEntry);
InterfaceClassEntry interfaceClassEntry = (InterfaceClassEntry) entry;
Expand All @@ -263,13 +260,15 @@ protected MethodEntry processMethod(DebugMethodInfo debugMethodInfo, DebugInfoBa
String methodName = debugMethodInfo.name();
int line = debugMethodInfo.line();
ResolvedJavaType resultType = debugMethodInfo.valueType();
String resultTypeName = resultType.toJavaName();
int modifiers = debugMethodInfo.modifiers();
DebugLocalInfo[] paramInfos = debugMethodInfo.getParamInfo();
DebugLocalInfo thisParam = debugMethodInfo.getThisParamInfo();
int paramCount = paramInfos.length;
debugContext.log("typename %s adding %s method %s %s(%s)%n",
typeName, memberModifiers(modifiers), resultTypeName, methodName, formatParams(paramInfos));
if (debugContext.isLogEnabled()) {
String resultTypeName = resultType.toJavaName();
debugContext.log("typename %s adding %s method %s %s(%s)%n",
typeName, memberModifiers(modifiers), resultTypeName, methodName, formatParams(paramInfos));
}
TypeEntry resultTypeEntry = debugInfoBase.lookupTypeEntry(resultType);
TypeEntry[] typeEntries = new TypeEntry[paramCount];
for (int i = 0; i < paramCount; i++) {
Expand Down
22 changes: 16 additions & 6 deletions ...tratevm/src/com.oracle.objectfile/src/com/oracle/objectfile/debugentry/DebugInfoBase.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -294,7 +294,9 @@ public void installDebugInfo(DebugInfoProvider debugInfoProvider) {
DebugTypeKind typeKind = debugTypeInfo.typeKind();
int byteSize = debugTypeInfo.size();

debugContext.log(DebugContext.INFO_LEVEL, "Register %s type %s ", typeKind.toString(), typeName);
if (debugContext.isLogEnabled(DebugContext.INFO_LEVEL)) {
debugContext.log(DebugContext.INFO_LEVEL, "Register %s type %s ", typeKind.toString(), typeName);
}
String fileName = debugTypeInfo.fileName();
Path filePath = debugTypeInfo.filePath();
addTypeEntry(idType, typeName, fileName, filePath, byteSize, typeKind);
Expand All @@ -307,7 +309,9 @@ public void installDebugInfo(DebugInfoProvider debugInfoProvider) {
String typeName = debugTypeInfo.typeName();
DebugTypeKind typeKind = debugTypeInfo.typeKind();

debugContext.log(DebugContext.INFO_LEVEL, "Process %s type %s ", typeKind.toString(), typeName);
if (debugContext.isLogEnabled(DebugContext.INFO_LEVEL)) {
debugContext.log(DebugContext.INFO_LEVEL, "Process %s type %s ", typeKind.toString(), typeName);
}
TypeEntry typeEntry = (idType != null ? lookupTypeEntry(idType) : lookupHeaderType());
typeEntry.addDebugInfo(this, debugTypeInfo, debugContext);
}));
Expand All @@ -329,7 +333,9 @@ public void installDebugInfo(DebugInfoProvider debugInfoProvider) {
ClassEntry classEntry = lookupClassEntry(ownerType);
MethodEntry methodEntry = classEntry.ensureMethodEntryForDebugRangeInfo(debugCodeInfo, this, debugContext);
PrimaryRange primaryRange = Range.createPrimary(methodEntry, lo, hi, primaryLine);
debugContext.log(DebugContext.INFO_LEVEL, "PrimaryRange %s.%s %s %s:%d [0x%x, 0x%x]", ownerType.toJavaName(), methodName, filePath, fileName, primaryLine, lo, hi);
if (debugContext.isLogEnabled(DebugContext.INFO_LEVEL)) {
debugContext.log(DebugContext.INFO_LEVEL, "PrimaryRange %s.%s %s %s:%d [0x%x, 0x%x]", ownerType.toJavaName(), methodName, filePath, fileName, primaryLine, lo, hi);
}
addPrimaryRange(primaryRange, debugCodeInfo, classEntry);
/*
* Record all subranges even if they have no line or file so we at least get a symbol
Expand Down Expand Up @@ -517,13 +523,17 @@ private Range addSubrange(DebugLocationInfo locationInfo, PrimaryRange primaryRa
SubRange subRange = Range.createSubrange(subRangeMethodEntry, lo, hi, line, primaryRange, caller, locationInfo.isLeaf());
classEntry.indexSubRange(subRange);
subRangeIndex.put(locationInfo, subRange);
debugContext.log(DebugContext.DETAILED_LEVEL, "SubRange %s.%s %d %s:%d [0x%x, 0x%x] (%d, %d)",
ownerType.toJavaName(), methodName, subRange.getDepth(), fullPath, line, lo, hi, loOff, hiOff);
if (debugContext.isLogEnabled(DebugContext.DETAILED_LEVEL)) {
debugContext.log(DebugContext.DETAILED_LEVEL, "SubRange %s.%s %d %s:%d [0x%x, 0x%x] (%d, %d)",
ownerType.toJavaName(), methodName, subRange.getDepth(), fullPath, line, lo, hi, loOff, hiOff);
}
assert (callerLocationInfo == null || (callerLocationInfo.addressLo() <= loOff && callerLocationInfo.addressHi() >= hiOff)) : "parent range should enclose subrange!";
DebugLocalValueInfo[] localValueInfos = locationInfo.getLocalValueInfo();
for (int i = 0; i < localValueInfos.length; i++) {
DebugLocalValueInfo localValueInfo = localValueInfos[i];
debugContext.log(DebugContext.DETAILED_LEVEL, " locals[%d] %s:%s = %s", localValueInfo.slot(), localValueInfo.name(), localValueInfo.typeName(), localValueInfo);
if (debugContext.isLogEnabled(DebugContext.DETAILED_LEVEL)) {
debugContext.log(DebugContext.DETAILED_LEVEL, " locals[%d] %s:%s = %s", localValueInfo.slot(), localValueInfo.name(), localValueInfo.typeName(), localValueInfo);
}
}
subRange.setLocalValueInfo(localValueInfos);
return subRange;
Expand Down
10 changes: 6 additions & 4 deletions ...tevm/src/com.oracle.objectfile/src/com/oracle/objectfile/debugentry/ForeignTypeEntry.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -87,10 +87,12 @@ public void addDebugInfo(DebugInfoBase debugInfoBase, DebugTypeInfo debugTypeInf
if (debugForeignTypeInfo.isSigned()) {
flags |= FLAG_SIGNED;
}
if (isPointer() && pointerTo != null) {
debugContext.log("foreign type %s flags 0x%x referent %s ", typeName, flags, pointerTo.getTypeName());
} else {
debugContext.log("foreign type %s flags 0x%x", typeName, flags);
if (debugContext.isLogEnabled()) {
if (isPointer() && pointerTo != null) {
debugContext.log("foreign type %s flags 0x%x referent %s ", typeName, flags, pointerTo.getTypeName());
} else {
debugContext.log("foreign type %s flags 0x%x", typeName, flags);
}
}
}

Expand Down
4 changes: 3 additions & 1 deletion ...m/src/com.oracle.objectfile/src/com/oracle/objectfile/debugentry/InterfaceClassEntry.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -56,7 +56,9 @@ public void addDebugInfo(DebugInfoBase debugInfoBase, DebugTypeInfo debugTypeInf

public void addImplementor(ClassEntry classEntry, DebugContext debugContext) {
implementors.add(classEntry);
debugContext.log("typename %s add implementor %s%n", typeName, classEntry.getTypeName());
if (debugContext.isLogEnabled()) {
debugContext.log("typename %s add implementor %s%n", typeName, classEntry.getTypeName());
}
}

public Stream<ClassEntry> implementors() {
Expand Down
4 changes: 3 additions & 1 deletion ...vm/src/com.oracle.objectfile/src/com/oracle/objectfile/debugentry/PrimitiveTypeEntry.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -59,7 +59,9 @@ public void addDebugInfo(DebugInfoBase debugInfoBase, DebugTypeInfo debugTypeInf
flags = debugPrimitiveTypeInfo.flags();
typeChar = debugPrimitiveTypeInfo.typeChar();
bitCount = debugPrimitiveTypeInfo.bitCount();
debugContext.log("typename %s %s (%d bits)%n", typeName, decodeFlags(), bitCount);
if (debugContext.isLogEnabled()) {
debugContext.log("typename %s %s (%d bits)%n", typeName, decodeFlags(), bitCount);
}
}

private String decodeFlags() {
Expand Down
6 changes: 4 additions & 2 deletions ...vm/src/com.oracle.objectfile/src/com/oracle/objectfile/debugentry/StructureTypeEntry.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -71,8 +71,10 @@ protected FieldEntry addField(DebugFieldInfo debugFieldInfo, DebugInfoBase debug
int fieldoffset = debugFieldInfo.offset();
boolean fieldIsEmbedded = debugFieldInfo.isEmbedded();
int fieldModifiers = debugFieldInfo.modifiers();
debugContext.log("typename %s adding %s field %s type %s%s size %s at offset 0x%x%n",
typeName, memberModifiers(fieldModifiers), fieldName, valueTypeName, (fieldIsEmbedded ? "(embedded)" : ""), fieldSize, fieldoffset);
if (debugContext.isLogEnabled()) {
debugContext.log("typename %s adding %s field %s type %s%s size %s at offset 0x%x%n",
typeName, memberModifiers(fieldModifiers), fieldName, valueTypeName, (fieldIsEmbedded ? "(embedded)" : ""), fieldSize, fieldoffset);
}
TypeEntry valueTypeEntry = debugInfoBase.lookupTypeEntry(valueType);
/*
* n.b. the field file may differ from the owning class file when the field is a
Expand Down
4 changes: 2 additions & 2 deletions substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/ProgressReporter.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -140,7 +140,7 @@ private enum BuildStage {
PARSING("Parsing methods", true, true),
INLINING("Inlining methods", true, false),
COMPILING("Compiling methods", true, true),
LAYOUTING("Layouting methods", true, true),
LAYING_OUT("Laying out methods", true, true),
CREATING("Creating image", true, true);

private static final int NUM_STAGES = values().length;
Expand Down Expand Up @@ -511,7 +511,7 @@ public ReporterClosable printCompiling() {
}

public ReporterClosable printLayouting() {
return print(TimerCollection.Registry.LAYOUT, BuildStage.LAYOUTING);
return print(TimerCollection.Registry.LAYOUT, BuildStage.LAYING_OUT);
}

// TODO: merge printCreationStart and printCreationEnd at some point (GR-35721).
Expand Down

0 comments on commit bd8874b

Please sign in to comment.