apm-agent-java icon indicating copy to clipboard operation
apm-agent-java copied to clipboard

Why can't I get the method‘s real parameter name when i use apm-agent?

Open hhhhhxm opened this issue 1 year ago • 16 comments

Why can't I get the method‘s real parameter name by reflect? i can get the method‘s real parameter name When the program first started,but i can‘t get the method's real parameter name after printing this log.

2023-07-14 13:58:27,588 [http-nio-8081-exec-4] INFO  co.elastic.apm.agent.servlet.ServletVersionInstrumentation - Servlet container info = Apache Tomcat/9.0.60

2023-07-14 13:58:27,710 [Attach Listener] INFO  co.elastic.apm.agent.impl.ElasticApmTracer - Tracer switched to RUNNING state

my code like this

@GetMapping("/test01")
    public String test01() throws NoSuchMethodException {
        Method testMethod = HelloController.class.getDeclaredMethod("test", int.class);
        for (Parameter parameter : testMethod.getParameters()) {
            System.out.println("param name is" + parameter.getName());
        }
        return "ok";
    }
    
    private static void test(int num) {

    }

and log info like this

param name isnum

2023-07-14 13:58:27,588 [http-nio-8081-exec-4] INFO  co.elastic.apm.agent.servlet.ServletVersionInstrumentation - Servlet container info = Apache Tomcat/9.0.60

2023-07-14 13:58:27,710 [Attach Listener] INFO  co.elastic.apm.agent.impl.ElasticApmTracer - Tracer switched to RUNNING state

param name isarg0

first result is “param name isnum” but the second result is “param name isarg0”,the expected result is “param name isnum”,how can i fix it?

my runtime environment is jdk8 and apm-agent-attach 1.39.0

hhhhhxm avatar Jul 14 '23 06:07 hhhhhxm

I'd guess that it gets lost when the class is transformed. Even if there is a way to maintain it (unlikely) we don't support that. Sorry

jackshirazi avatar Jul 14 '23 09:07 jackshirazi

However, this causes MyBatis to fail sql execution without explicitly specifying the parameter name using @param. The error message is as follows: org.mybatis.spring.MyBatisSystemException: nested exception is org.apache.ibatis.binding.BindingException: Parameter 'ids' not found. Available parameters are [collection, list]。 @jackshirazi

barlowHua avatar Jul 14 '23 09:07 barlowHua

@jackshirazi I think it not impact mybatis, but also all frameworks that need to get some information by java reflect mechanism, so I think it is a bug that need to fix

I321065 avatar Jul 14 '23 10:07 I321065

There is no guarantee in Java that a parameter name is retained, if you compile without debugging information it wouldn't be. Any framework that relies on that is buggy. I appreciate this is frustrating for you but we won't be priortising any work on this. Perhaps raising the issue with MyBatis might help?

jackshirazi avatar Jul 14 '23 10:07 jackshirazi

@jackshirazi I partially agree with your point, but this issue was introduced starting from version 1.25.0 not exists before, so it would cause regression issues for upgrading users and it is not mentioned in release notes, so I do not think not supporting is reasonable, please reestimate this issue, thanks!!!

I321065 avatar Jul 14 '23 10:07 I321065

I really can't see this as a bug or breaking change in the agent, MyBatis is erroring on a implementation detail that is explicitly not guaranteed to hold in the JVM. Possible workarounds for you (but I don't know it will prevent the error):

  • disable the jdbc instrumentation
  • compile the Java code with -parameter

jackshirazi avatar Jul 14 '23 10:07 jackshirazi

@jackshirazi apm will erase the method real name even though I compile java code with -parameter, this is my concerned; besides mybatis, I also found feign have the same problem, so please reopen this issue and schedule to resolve it;

img_v2_d8be9a17-f378-4c53-bdca-bc5fed2e8a7g

I321065 avatar Sep 19 '23 07:09 I321065

I think it is hard to upgrade if this issue can not resolve, because I need to care all codes that use this feature @jackshirazi

I321065 avatar Sep 19 '23 07:09 I321065

I've reopened it, but I still don't see this as an agent bug, more a feature request. But whether bug or feature request, this is not prioritized for the current quarter

jackshirazi avatar Sep 20 '23 17:09 jackshirazi

I tried to reproduce the issue and did not succeed at it using:

  • a recent java8 version (8u385)
  • Main.java (see below)
import java.lang.reflect.Method;

public class Main {
    public static void main(String[] args){
        toInstrument(args);
    }

    public static void toInstrument(String[] args){
        test(Main.class);
    }

    public static void test(Class<?> type){
        Method[] methods = type.getDeclaredMethods();
        for (Method method : methods) {
            for (int i = 0; i < method.getParameterCount(); i++) {
                String name = method.getParameters()[i].getName();
                if (name.startsWith("arg0")) {
                    throw new IllegalArgumentException("boom !");
                } else {
                    System.out.println("arg ok: " + name);
                }
            }
        }
    }

}

Without the agent, when compiled with javac Main.java then we get an exception as expected when running it with java Main. Still without the agent, when compiled with javac -parameters Main.java it works as expected.

On the bytecode level when looking at it with javap, the difference is that when the -parameters argument is provided to the compiler the genereted bytecode will include an extra MethodParameters section at the end of each method, here for toInstrument method above with the option:

  public static void toInstrument(java.lang.String[]);
    descriptor: ([Ljava/lang/String;)V
    flags: ACC_PUBLIC, ACC_STATIC
    Code:
      stack=1, locals=1, args_size=1
         0: ldc           #3                  // class Main
         2: invokestatic  #4                  // Method test:(Ljava/lang/Class;)V
         5: return
      LineNumberTable:
        line 9: 0
        line 10: 5
    MethodParameters:
      Name                           Flags
      args

When adding the agent with -javaagent JVM argument and by configuring it with trace_methods=Main#toInstrument, the toInstrument method is instrumented as a transaction, and the method parameter names are preserved.

In order to verify what is happening here, it would be required to investigate the bytecode that is modified by the agent, in order to do that you will have to set bytecode_dump_path option to an empty folder and this will write the classes before and after instrumentation, then they could be compared by using a tool like javap.

How does the agent is setup in your applications here ? is is using -javaagent or does it uses on the runtime attach ? The initial report from @hhhhhxm seemed to indicate that it was using runtime attach.

The part that confuses me the most is that two invocations of the same method might yield different results, which seems to be more a JVM bug when the code is instrumented rather than something that the agent has control over. Here, having the exact JVM version that you are using would also be relevant.

SylvainJuge avatar Nov 16 '23 13:11 SylvainJuge

We had the same problem with JDK 17. The most important core feature, Spring SPEL, which is used in hundreds of our microservices, cannot work because the parameter names are erased. To be honest, I don't think Spring SPEL is a decent design relying on the parameter names, but this is what it is, the world most popular framework. Appreciate if you guys can reconsider whether or not to keep the parameter names.

DanielYWoo avatar May 31 '24 06:05 DanielYWoo

Hi @DanielYWoo , this is not something that is in our control as the agent just reads the existing bytecode that was compiled by the Java compiler. If the bytecode does not contain the information, there is nothing we can do to restore it.

In order to investigate further your case I would suggest to inspect the compiled classes with javap to see if the parameter names are preserved in the bytecode or not.

If they aren't, then you need to find the right parameters for the javac compiler to keep them.

SylvainJuge avatar May 31 '24 08:05 SylvainJuge

Hi @DanielYWoo , this is not something that is in our control as the agent just reads the existing bytecode that was compiled by the Java compiler. If the bytecode does not contain the information, there is nothing we can do to restore it.

In order to investigate further your case I would suggest to inspect the compiled classes with javap to see if the parameter names are preserved in the bytecode or not.

If they aren't, then you need to find the right parameters for the javac compiler to keep them.

Thanks for the tips but we do have the debug info. Sorry I don't have enough time to further debug this, fortunately the agent allows us to customize the instrument filters, so now we exclude the affected classes here and there to temporarily make it work.

DanielYWoo avatar May 31 '24 17:05 DanielYWoo

BTW, we also purchased another commercial APM tool which works without a problem. So I believe this could be a tricky bug in Elastic APM agent. But I just don't have time to take a deep look at this. (I am still working at 1:15 AM Saturday right now)

DanielYWoo avatar May 31 '24 17:05 DanielYWoo

Sorry, I completely misunderstood the issue here. I thought that the parameter names were not included in the original bytecode.

However here the problem is that code that gets instrumented apparently looses the parameter names once transformed, which is a bit different.

SylvainJuge avatar Jun 03 '24 07:06 SylvainJuge

You are using "runtime attach" setup method, does the same issue also happens when you are using the -javaagent JVM command-line option ?

That would be interesting (and quite quick) to know here, apparently some older JVMs discard the argument names when re-defining classes, which happens when using runtime attach. When using -javaagent setup method the classes the instrumentation happens before the classes are loaded for the first time, hence this problem might not appear.

SylvainJuge avatar Jun 03 '24 11:06 SylvainJuge