support verbose log for self diagnosing

demo/java-demo/src/test/java/com/alibaba/testable/demo/DemoMockTest.java

@@ -8,8 +8,8 @@ import org.junit.jupiter.api.Test;
 import java.util.concurrent.Executors;
 
 import static com.alibaba.testable.core.matcher.InvokeVerifier.verify;
-import static com.alibaba.testable.core.tool.TestableTool.SOURCE_METHOD;
 import static com.alibaba.testable.core.tool.TestableTool.MOCK_CONTEXT;
+import static com.alibaba.testable.core.tool.TestableTool.SOURCE_METHOD;
 import static org.junit.jupiter.api.Assertions.assertEquals;
 
 /**

testable-agent/src/main/java/com/alibaba/testable/agent/handler/SourceClassHandler.java

@@ -65,24 +65,12 @@ public class SourceClassHandler extends BaseClassHandler {
         do {
             if (invokeOps.contains(instructions[i].getOpcode())) {
                 MethodInsnNode node = (MethodInsnNode)instructions[i];
-                MethodInfo mockMethod = getMemberInjectMethodName(memberInjectMethods, node);
+                if (ConstPool.CONSTRUCTOR.equals(node.name)) {
-                if (mockMethod != null) {
+                    LogUtil.verbose("     Line %d, constructing \"%s\" as \"%s\"", getLineNum(instructions, i),
-                    // it's a member or static method and an inject method for it exist
+                        node.owner, node.desc);
-                    int rangeStart = getMemberMethodStart(instructions, i);
-                    if (rangeStart >= 0) {
-                        ModifiedInsnNodes modifiedInsnNodes = replaceMemberCallOps(cn, mn, mockMethod,
-                            instructions, node.owner, node.getOpcode(), rangeStart, i);
-                        instructions = modifiedInsnNodes.nodes;
-                        maxStackDiff = Math.max(maxStackDiff, modifiedInsnNodes.stackDiff);
-                        i = rangeStart;
-                    } else {
-                        LogUtil.warn("Potential missed mocking at %s:%s", mn.name, getLineNum(instructions, i));
-                    }
-                } else if (ConstPool.CONSTRUCTOR.equals(node.name)) {
-                    // it's a new operation
                     String newOperatorInjectMethodName = getNewOperatorInjectMethodName(newOperatorInjectMethods, node);
                     if (newOperatorInjectMethodName != null) {
-                        // and an inject method for it exist
+                        // it's a new operation and an inject method for it exist
                         int rangeStart = getConstructorStart(instructions, node.owner, i);
                         if (rangeStart >= 0) {
                             ModifiedInsnNodes modifiedInsnNodes = replaceNewOps(cn, mn, newOperatorInjectMethodName,
@@ -92,6 +80,23 @@ public class SourceClassHandler extends BaseClassHandler {
                             i = rangeStart;
                         }
                     }
+                } else {
+                    LogUtil.verbose("     Line %d, invoking \"%s\" as \"%s\"", getLineNum(instructions, i),
+                        node.name, node.desc);
+                    MethodInfo mockMethod = getMemberInjectMethodName(memberInjectMethods, node);
+                    if (mockMethod != null) {
+                        // it's a member or static method and an inject method for it exist
+                        int rangeStart = getMemberMethodStart(instructions, i);
+                        if (rangeStart >= 0) {
+                            ModifiedInsnNodes modifiedInsnNodes = replaceMemberCallOps(cn, mn, mockMethod,
+                                instructions, node.owner, node.getOpcode(), rangeStart, i);
+                            instructions = modifiedInsnNodes.nodes;
+                            maxStackDiff = Math.max(maxStackDiff, modifiedInsnNodes.stackDiff);
+                            i = rangeStart;
+                        } else {
+                            LogUtil.warn("Potential missed mocking at %s:%s", mn.name, getLineNum(instructions, i));
+                        }
+                    }
                 }
             }
             i++;
@@ -194,7 +199,7 @@ public class SourceClassHandler extends BaseClassHandler {
 
     private ModifiedInsnNodes replaceNewOps(ClassNode cn, MethodNode mn, String newOperatorInjectMethodName,
                                              AbstractInsnNode[] instructions, int start, int end) {
-        LogUtil.diagnose("    Line %d, mock method %s used", getLineNum(instructions, start),
+        LogUtil.diagnose("    Line %d, mock method \"%s\" used", getLineNum(instructions, start),
             newOperatorInjectMethodName);
         String classType = ((TypeInsnNode)instructions[start]).desc;
         String constructorDesc = ((MethodInsnNode)instructions[end]).desc;
@@ -224,7 +229,7 @@ public class SourceClassHandler extends BaseClassHandler {
     private ModifiedInsnNodes replaceMemberCallOps(ClassNode cn, MethodNode mn, MethodInfo mockMethod,
                                                    AbstractInsnNode[] instructions, String ownerClass,
                                                    int opcode, int start, int end) {
-        LogUtil.diagnose("    Line %d, mock method %s used", getLineNum(instructions, start),
+        LogUtil.diagnose("    Line %d, mock method \"%s\" used", getLineNum(instructions, start),
             mockMethod.getMockName());
         boolean shouldAppendTypeParameter = !mockMethod.getDesc().equals(mockMethod.getMockDesc());
         String testClassName = ClassUtil.getTestClassName(cn.name);

testable-agent/src/main/java/com/alibaba/testable/agent/transformer/TestableClassTransformer.java

@@ -57,8 +57,8 @@ public class TestableClassTransformer implements ClassFileTransformer {
         try {
             if (shouldTransformAsSourceClass(className)) {
                 // it's a source class with testable enabled
-                LogUtil.diagnose("Handling source class %s", className);
                 List<MethodInfo> injectMethods = getTestableMockMethods(ClassUtil.getTestClassName(className));
+                LogUtil.diagnose("Handling source class %s", className);
                 bytes = new SourceClassHandler(injectMethods).getBytes(classFileBuffer);
                 dumpByte(className, bytes);
                 resetMockContext();
@@ -140,9 +140,12 @@ public class TestableClassTransformer implements ClassFileTransformer {
         for (AnnotationNode an : mn.visibleAnnotations) {
             String fullClassName = toDotSeparateFullClassName(an.desc);
             if (fullClassName.equals(ConstPool.MOCK_CONSTRUCTOR)) {
+                LogUtil.verbose("   Mock constructor \"%s\" as \"(%s)V\" for \"%s\"", mn.name,
+                    ClassUtil.extractParameters(mn.desc), ClassUtil.getReturnType(mn.desc));
                 addMockConstructor(methodInfos, cn, mn);
             } else if (fullClassName.equals(ConstPool.MOCK_METHOD) ||
                        fullClassName.equals(ConstPool.TESTABLE_MOCK)) {
+                LogUtil.verbose("   Mock method \"%s\" as \"%s\"", mn.name, mn.desc);
                 String targetMethod = AnnotationUtil.getAnnotationParameter(
                     an, ConstPool.FIELD_TARGET_METHOD, mn.name, String.class);
                 if (ConstPool.CONSTRUCTOR.equals(targetMethod)) {
@@ -218,7 +221,8 @@ public class TestableClassTransformer implements ClassFileTransformer {
     private void setupMockContext(AnnotationNode an) {
         MockDiagnose diagnose = AnnotationUtil.getAnnotationParameter(an, FIELD_DIAGNOSE, null, MockDiagnose.class);
         if (diagnose != null) {
-            LogUtil.enableDiagnose(diagnose == MockDiagnose.ENABLE);
+            LogUtil.setLevel(diagnose == MockDiagnose.ENABLE ? LogUtil.LogLevel.LEVEL_DIAGNOSE :
+                (diagnose == MockDiagnose.VERBOSE ? LogUtil.LogLevel.LEVEL_VERBOSE : LogUtil.LogLevel.LEVEL_MUTE));
         }
     }
 

testable-agent/src/main/java/com/alibaba/testable/agent/util/ClassUtil.java

@@ -140,6 +140,16 @@ public class ClassUtil {
         return parameterTypes;
     }
 
+    /**
+     * extract parameter part of method desc
+     * @param desc method description
+     * @return parameter value
+     */
+    public static String extractParameters(String desc) {
+        int returnTypeEdge = desc.lastIndexOf(PARAM_END);
+        return desc.substring(1, returnTypeEdge);
+    }
+
     /**
      * parse method desc, fetch return value types
      * @param desc method description

testable-agent/src/test/java/com/alibaba/testable/agent/util/ClassUtilTest.java

@@ -15,6 +15,12 @@ class ClassUtilTest {
         assertEquals(3, ClassUtil.getParameterTypes("(Ljava/lang/String;[I[Ljava/lang/String;)V").size());
     }
 
+    @Test
+    void should_able_to_extract_parameter() {
+        assertEquals("", ClassUtil.extractParameters("()I"));
+        assertEquals("Ljava/lang/String;", ClassUtil.extractParameters("(Ljava/lang/String;)I"));
+    }
+
     @Test
     void should_able_to_get_return_type() {
         assertEquals("", ClassUtil.getReturnType("(Ljava/lang/String;)V"));

testable-core/src/main/java/com/alibaba/testable/core/model/MockDiagnose.java

@@ -14,6 +14,11 @@ public enum MockDiagnose {
     /**
      * Print diagnose logs
      */
-    ENABLE
+    ENABLE,
+
+    /**
+     * Print verbose log
+     */
+    VERBOSE
 
 }

testable-core/src/main/java/com/alibaba/testable/core/util/LogUtil.java

@@ -54,8 +54,8 @@ public class LogUtil {
         System.err.println(String.format("[ERROR] " + msg, args));
     }
 
-    public static void enableDiagnose(boolean enable) {
+    public static void setLevel(LogLevel level) {
-        currentLogLevel = enable ? LogLevel.LEVEL_DIAGNOSE : LogLevel.LEVEL_MUTE;
+        currentLogLevel = level;
     }
 
     public static void setDefaultLevel(LogLevel level) {