I have create a mini-logger for methods, and I use ASM. I need to determine by descriptor method parameters and print it. But I have an error
Exception in thread "main" java.lang.VerifyError: Bad type on operand stack
Exception Details:
Location:
ru/otus/TestLogging.calc(IFD)V @6: invokedynamic
Reason:
Type 'java/io/PrintStream' (current frame, stack[4]) is not assignable to double_2nd
Current Frame:
bci: @6
flags: { }
locals: { 'ru/otus/TestLogging', integer, float, double, double_2nd }
stack: { 'ru/otus/TestLogging', float, double, double_2nd, 'java/io/PrintStream' }
Bytecode:
0000000: 2a24 29b2 0007 ba00 3e00 00b6 0011 b200
0000010: 071b 2429 ba00 0d00 00b6 0011 b1
This is code my Agent
public class Agent {
public static void premain(String agentArgs, Instrumentation inst) {
inst.addTransformer(new ClassFileTransformer() {
@Override
public byte[] transform(ClassLoader loader,
String className,
Class<?> classBeingRedefined,
ProtectionDomain protectionDomain,
byte[] classfileBuffer) throws IllegalClassFormatException {
if(className.contains("ru/otus/")) {
return changeMethod(classfileBuffer, className);
}
return classfileBuffer;
}
});
}
private static byte[] changeMethod(byte[] originalClass, String className) {
ClassReader reader = new ClassReader(originalClass);
ClassWriter writer = new ClassWriter(reader, ClassWriter.COMPUTE_MAXS);
ArrayList<String> list = new ArrayList<>();
ClassVisitor visitor = new ClassVisitor(Opcodes.ASM5, writer) {
@Override
public MethodVisitor visitMethod(int access, String name, String descriptor, String signature, String[] exceptions){
System.out.println("visitMethod: access="+access+" name="+name+" desc="+descriptor+" signature="+signature+" exceptions="+exceptions);
Method thisMethod = new Method(name, descriptor);
MethodVisitor mv = new MethodAnnotationScanner(Opcodes.ASM5, super.visitMethod(access, name, descriptor, signature, exceptions), thisMethod, className);
return mv;
}
};
reader.accept(visitor, Opcodes.ASM5);
for(String methodName : list) {
System.out.println(methodName);
}
byte[] finalClass = writer.toByteArray();
if(className.contains("Test")) {
try (OutputStream fos = new FileOutputStream("TestLogging.class")) {
fos.write(finalClass);
} catch (Exception e) {
e.printStackTrace();
}
}
return writer.toByteArray();
}
static class MethodAnnotationScanner extends MethodVisitor {
private Method thisMethod;
private boolean isChangeMethod = false;
private String className = null;
private StringBuilder descriptor = new StringBuilder("(");
public MethodAnnotationScanner(int api, MethodVisitor methodVisitor, Method thisMethod, String className) {
super(api, methodVisitor);
this.thisMethod = thisMethod;
this.className = className;
}
@Override
public AnnotationVisitor visitAnnotation(String desc, boolean visible) {
System.out.println("visitAnnotation: desc="+desc+" visible="+visible);
if(desc.contains("ru/otus/annotations/Log")) {
this.isChangeMethod = true;
return super.visitAnnotation(desc, visible);
}
this.isChangeMethod = false;
return super.visitAnnotation(desc, visible);
}
@Override
public void visitCode() {
if(this.isChangeMethod) {
super.visitVarInsn(Opcodes.ALOAD, 0);
int i = 1;
for(Type arg : thisMethod.getArgumentTypes()) {
this.descriptor.append(arg.getDescriptor());
if (arg.getDescriptor().equals("J")) {
super.visitVarInsn(Opcodes.LLOAD, i);
++i;
} else if (arg.getDescriptor().equals("D")) {
super.visitVarInsn(Opcodes.DLOAD, i);
++i;
} else if (arg.getDescriptor().equals("F")) {
super.visitVarInsn(Opcodes.FLOAD, i);
} else if(arg.getDescriptor().equals("I")) {
super.visitVarInsn(Opcodes.ILOAD, i);
}
i++;
}
Handle handle = new Handle(
H_INVOKESTATIC,
Type.getInternalName(java.lang.invoke.StringConcatFactory.class),
"makeConcatWithConstants",
MethodType.methodType(CallSite.class, MethodHandles.Lookup.class, String.class, MethodType.class, String.class, Object[].class).toMethodDescriptorString(),
false);
this.descriptor.append(")Ljava/lang/String;");
super.visitFieldInsn(Opcodes.GETSTATIC, "java/lang/System", "out", "Ljava/io/PrintStream;");
super.visitInvokeDynamicInsn("makeConcatWithConstants", this.descriptor.toString(), handle, "executed method: " + this.thisMethod.getName() + ", param: \u0001".repeat(i));
super.visitMethodInsn(Opcodes.INVOKEVIRTUAL, "java/io/PrintStream", "println", "(Ljava/lang/String;)V", false);
super.visitMaxs(0, 0);
}
if (mv != null) {
super.visitCode();
}
super.visitEnd();
}
}
}
I have two classes to reproduce this feature. first - TestLogging second - AutoLogger
In the first class I have a methods which need to logged, In second it's start class contains method main.
You are pushing the arguments for the string concatenation before reading the field System.out, followed by attempting to perform the string concatenation. So the invokedynamic instruction intended to perform the string concatenation finds a mismatching PrintStream on the operand stack.
A simple fix is to change the instructions
super.visitFieldInsn(Opcodes.GETSTATIC, "java/lang/System", "out", "Ljava/io/PrintStream;");
super.visitInvokeDynamicInsn("makeConcatWithConstants", this.descriptor.toString(), handle, "executed method: " + this.thisMethod.getName() + ", param: \u0001".repeat(i));
super.visitMethodInsn(Opcodes.INVOKEVIRTUAL, "java/io/PrintStream", "println", "(Ljava/lang/String;)V", false);
to
super.visitInvokeDynamicInsn("makeConcatWithConstants", this.descriptor.toString(), handle, "executed method: " + this.thisMethod.getName() + ", param: \u0001".repeat(i));
super.visitFieldInsn(Opcodes.GETSTATIC, "java/lang/System", "out", "Ljava/io/PrintStream;");
super.visitInsn(Opcodes.SWAP);
super.visitMethodInsn(Opcodes.INVOKEVIRTUAL, "java/io/PrintStream", "println", "(Ljava/lang/String;)V", false);
Or move the GETSTATIC before the code that will push the concat arguments, to the place where you perform the obsolete super.visitVarInsn(Opcodes.ALOAD, 0);. Then, you don’t need SWAP.
But there are more problems with the code. You are counting the local variables while pushing the values, correctly considering long and double to take two variables, but then, you are using the same number in the ", param: \u0001".repeat(i) expression, which will tell the StringConcatFactory that there were two values in case of long and double. You need to separate the counters. Also, you are not pushing reference type arguments, but since you are counting them and including them in the signature for the concat invocation, you must also push them to the operand stack.
Further, while not having an effect here, the visitMaxs(0, 0) call and the visitEnd() call are inappropriate. You are injecting at the beginning of the code and the other visit calls, which you will not intercept, will follow, including an automatically performed visitMaxs and visitEnd.
With all fixes, the code looks like
public void visitCode() {
if(this.isChangeMethod) {
super.visitFieldInsn(Opcodes.GETSTATIC, "java/lang/System", "out", "Ljava/io/PrintStream;");
int varIndex = 1, numArgs = 0;
for(Type arg : thisMethod.getArgumentTypes()) {
this.descriptor.append(arg.getDescriptor());
if (arg.getDescriptor().equals("J")) {
super.visitVarInsn(Opcodes.LLOAD, varIndex);
++varIndex;
} else if (arg.getDescriptor().equals("D")) {
super.visitVarInsn(Opcodes.DLOAD, varIndex);
++varIndex;
} else if (arg.getDescriptor().equals("F")) {
super.visitVarInsn(Opcodes.FLOAD, varIndex);
} else if(arg.getDescriptor().equals("I")) {
super.visitVarInsn(Opcodes.ILOAD, varIndex);
} else {
super.visitVarInsn(Opcodes.ALOAD, varIndex);
}
varIndex++;
numArgs++;
}
Handle handle = new Handle(
H_INVOKESTATIC,
Type.getInternalName(java.lang.invoke.StringConcatFactory.class),
"makeConcatWithConstants",
MethodType.methodType(CallSite.class, MethodHandles.Lookup.class, String.class, MethodType.class, String.class, Object[].class).toMethodDescriptorString(),
false);
this.descriptor.append(")Ljava/lang/String;");
super.visitInvokeDynamicInsn("makeConcatWithConstants", this.descriptor.toString(), handle, "executed method: " + this.thisMethod.getName() + ", param: \u0001".repeat(numArgs));
super.visitMethodInsn(Opcodes.INVOKEVIRTUAL, "java/io/PrintStream", "println", "(Ljava/lang/String;)V", false);
}
super.visitCode();
}
As a side note, when you are pushing all arguments for the concatenation, you can simplify the descriptor construction, as the concat descriptor is almost identical to the method’s descriptor; you only have to replace the return type with Ljava/lang/String;.
You can do the entire operation without dealing with Method and Type objects, just using the two strings already passed to visitMethod.
@Override
public MethodVisitor visitMethod(int access, String name, String descriptor,
String signature, String[] exceptions) {
System.out.println("visitMethod: access="+access+" name="+name
+" desc="+descriptor+" signature="+signature+" exceptions="+exceptions);
MethodVisitor mv = new MethodAnnotationScanner(Opcodes.ASM5, name, descriptor,
super.visitMethod(access, name, descriptor, signature, exceptions));
return mv;
}
static class MethodAnnotationScanner extends MethodVisitor {
private boolean isChangeMethod;
private final String name, descriptor;
public MethodAnnotationScanner(int api, String name,
String methodDesciptor, MethodVisitor methodVisitor){
super(api, methodVisitor);
this.name = name;
this.descriptor = methodDesciptor;
}
@Override
public AnnotationVisitor visitAnnotation(String desc, boolean visible) {
System.out.println("visitAnnotation: desc="+desc+" visible="+visible);
if(desc.contains("ru/otus/annotations/Log")) {
this.isChangeMethod = true;
return super.visitAnnotation(desc, visible);
}
this.isChangeMethod = false;
return super.visitAnnotation(desc, visible);
}
@Override
public void visitCode() {
if(this.isChangeMethod) {
super.visitFieldInsn(Opcodes.GETSTATIC,
"java/lang/System", "out", "Ljava/io/PrintStream;");
int varIndex = 1, numArgs = 0, p;
for(p = 1; descriptor.charAt(p) != ')'; p++) {
switch(descriptor.charAt(p)) {
case 'J':
super.visitVarInsn(Opcodes.LLOAD, varIndex); ++varIndex; break;
case 'D':
super.visitVarInsn(Opcodes.DLOAD, varIndex); ++varIndex; break;
case 'F': super.visitVarInsn(Opcodes.FLOAD, varIndex); break;
case 'I': super.visitVarInsn(Opcodes.ILOAD, varIndex); break;
case 'L': super.visitVarInsn(Opcodes.ALOAD, varIndex);
p = descriptor.indexOf(';', p);
break;
case '[': super.visitVarInsn(Opcodes.ALOAD, varIndex);
do {} while(descriptor.charAt(++p)=='[');
if(descriptor.charAt(p) == 'L') p = descriptor.indexOf(';', p);
break;
default: throw new IllegalStateException(descriptor);
}
varIndex++;
numArgs++;
}
String ret = "Ljava/lang/String;";
String concatSig = new StringBuilder(++p + ret.length())
.append(descriptor, 0, p).append(ret).toString();
Handle handle = new Handle(
H_INVOKESTATIC,
"java/lang/invoke/StringConcatFactory",
"makeConcatWithConstants",
MethodType.methodType(CallSite.class, MethodHandles.Lookup.class,
String.class, MethodType.class, String.class, Object[].class)
.toMethodDescriptorString(),
false);
super.visitInvokeDynamicInsn("makeConcatWithConstants", concatSig, handle,
"executed method: " + name + ", param: \u0001".repeat(numArgs));
super.visitMethodInsn(Opcodes.INVOKEVIRTUAL,
"java/io/PrintStream", "println", "(Ljava/lang/String;)V", false);
}
super.visitCode();
}
}