Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

updating agent detection in filter #660

Merged
merged 1 commit into from
May 30, 2018
Merged

Conversation

dhaval24
Copy link
Contributor

@dhaval24 dhaval24 commented May 4, 2018

This PR helps in detecting Agent Jar in a better way inside WebRequestTrackingFilter. Instead of calling the Instance of AgentConnector and failing with an exception when Jar is not present this, explicitly tries to see if the AgentNotificationsHandler is present on the classPath. This prevents from throwing unnecessary exception.

Copying my comment from #646

I wanted to point out the following: By reverting the changes of how agent is detected to the original implementation, the user will see this misleading exception message when the Agent Jar is not present.

AI: ERROR 04-05-2018 09:08:53.150, 31(localhost-startStop-1): Could not find Agent: 'java.lang.NoClassDefFoundError: com/microsoft/applicationinsights/agent/internal/coresync/AgentNotificationsHandler
at java.lang.ClassLoader.defineClass1(Native Method)
at java.lang.ClassLoader.defineClass(ClassLoader.java:763)
at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142)
at java.net.URLClassLoader.defineClass(URLClassLoader.java:467)
at java.net.URLClassLoader.access$100(URLClassLoader.java:73)
at java.net.URLClassLoader$1.run(URLClassLoader.java:368)
at java.net.URLClassLoader$1.run(URLClassLoader.java:362)
at java.security.AccessController.doPrivileged(Native Method)
at java.net.URLClassLoader.findClass(URLClassLoader.java:361)
at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:338)
at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
at com.microsoft.applicationinsights.internal.agent.AgentConnector.register(AgentConnector.java:79)
at com.microsoft.applicationinsights.web.internal.WebRequestTrackingFilter.registerWebApp(WebRequestTrackingFilter.java:287)
at com.microsoft.applicationinsights.web.internal.WebRequestTrackingFilter.initialize(WebRequestTrackingFilter.java:263)
at com.microsoft.applicationinsights.web.internal.WebRequestTrackingFilter.init(WebRequestTrackingFilter.java:145)
at org.apache.catalina.core.ApplicationFilterConfig.initFilter(ApplicationFilterConfig.java:285)
at org.apache.catalina.core.ApplicationFilterConfig.(ApplicationFilterConfig.java:112)
at org.apache.catalina.core.StandardContext.filterStart(StandardContext.java:4590)
at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5233)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1419)
at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1409)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.ClassNotFoundException: com.microsoft.applicationinsights.agent.internal.coresync.AgentNotificationsHandler
at java.net.URLClassLoader.findClass(URLClassLoader.java:381)
at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:338)
at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
... 27 more

IMO, this is very confusing and I can remember couple of tickets when users pointed out to this weired behavior.

My suggestion : We can take two approaches -

  1. Either avoid dumping stackTrace for this scenario. (Caution: We will also miss any other exceptions
    which might come up here).
  2. Change the way how agent is detected. I will submit another PR as requested.

This PR implements the second option, because effectively when a runtime exception is thrown compiler has to jump instructions which makes the program terribly slow. You can look at more details on this thread (https://stackoverflow.com/questions/299068/how-slow-are-java-exceptions)
Further, users expect exceptions when a bad behavior happens in the program, not for what is expected to be usual behavior. This is also considered seriously bad practice. I would strongly urge to have a better way for detecting agent. I propose one in another PR, if there is a better alternative I am happy to evaluate it.

@dhaval24 dhaval24 self-assigned this May 4, 2018
@dhaval24 dhaval24 requested review from littleaj and grlima May 4, 2018 21:43
Copy link
Contributor

@littleaj littleaj left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Made a few comments for investigation.

also, regarding the stacktrace in your PR summary: what environment did that come from?

When I tested this, it failed to line 245 (left file); but the stack trace is further down. We should figure out why.

public class CommonUtils {
public static boolean isNullOrEmpty(String string) {
return string == null || string.length() == 0;
public static boolean isNullOrEmpty(String string) {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It looks like your IDE is making adjustments to spacing during commit or save or something. Let's try not to do this since it makes diffs harder to read.

Copy link
Contributor Author

@dhaval24 dhaval24 May 4, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please provide me with the Intellij settings that you use, so I can try to be consistent by modifying my settings

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't use the intellij formatter

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hm, it would be difficult to find the right settings then. May be it's using 4 space as default. I can do that.

}
}
//If Agent Jar is not present in the class path skip the process
if (!CommonUtils.isClassPresentOnClassPath(AGENT_LOCATOR_INTERFACE_NAME,
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Since this operation is being timed, let's get 5 samples of this running to a successful and a failed state. We should understand the perf impact of this change.

Copy link
Contributor Author

@dhaval24 dhaval24 May 5, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@littleaj here is the comparison result in my local box:

Without changes:
Without agent - (0.119ms, 0.234ms, 0.133ms, 0.212ms, 0.189ms)
Average : 0.177ms
With Agent - (149.670ms, 157.744ms, 158.322ms, 148.388ms, 156.908ms)
Average: 154.206ms
With changes:
Without agent: - (0.206ms, 0.209ms, 0.212ms, 0.236ms, 0.231ms)
Average: 0.218ms
With agent: - (151.313ms, 153.400ms, 158.664ms, 144.721ms, 149.239ms)
Average: 151.467ms

Overhead with changes:
Without Agent: 0.041ms (average)
With Agent: Approximately the same.
This was tested on SpringBoot setup, not a hello world code so classloader would have all SpringBoot classes in it.

It seems like the results without agent are little bit larger with the changes, but it's in the order of nano seconds. Personally, it won't hurt but we can make one more sanity check on lowest VM configuration if you think that is a good step. Let me know your thoughts.

Copy link
Contributor

@littleaj littleaj May 7, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Cool, that means with this app we see it perform ~23.3% slower in the failure case (agent not found) and ~1.77% faster in the success case (agent found). The slowdown is significant, but since that case is on the order of microseconds, I think this is reasonable and we shouldn't see a noticeable impact on slower hardware.

We should do the same test on a "hello world" app just to confirm the assumption that more dependency classes means more time in Class.forName. That'll give us a bit more insight into how this will scale.

@grlima, what do you think?

@dhaval24
Copy link
Contributor Author

dhaval24 commented May 4, 2018

@littleaj I have tried in SpringBoot scenario, configuring with traditional XML in Windows environment. Now I am not sure why it fails at line 245. which I believe in the previous file is this -

AgentConnector test = AgentConnector.INSTANCE;

AgentConnector class lies in the core module and is always present. Precisely this is the path : com.microsoft.applicationinsights.internal.agent

However when the call to AgentConnector.RegistrationResult result = AgentConnector.INSTANCE.register(this.getClass().getClassLoader(), name); this happens in the register method it tries to create a new object of CoreAgentNotificationHandler which implements AgentNotificationHandler (part of agent code) and that's where the exception comes from.

This should make it more clear.

@littleaj
Copy link
Contributor

littleaj commented May 4, 2018

It appears that sometimes it throws NoClassDefFoundError when line 245 is hit. Other times it throws later, as seen in your stacktrace. It is unclear why there is this difference in behavior.

@dhaval24
Copy link
Contributor Author

@littleaj @grlima here are the results after the change for with Agent and without agent scenario in Azure Linux B1 VM (basic configuration)

With Agent:

  1. 819.749ms
    2.781.807ms
    3.813.892ms
    4.790.538ms
    5.782.718ms

Average = 797.740ms

Without Agent:

  1. 10.699ms
  2. 13.652ms
  3. 17.033ms
  4. 11.316ms
  5. 10.499ms

Average = 12.639ms

The test is performed with same springboot application (without using starter)

Copy link
Contributor

@littleaj littleaj left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Perf seems reasonable to me (assuming everything scales linearly)

@dhaval24
Copy link
Contributor Author

@littleaj thanks for approving, I will then go ahead and merge provided there are no other concerns.

@dhaval24 dhaval24 merged commit bf34c83 into master May 30, 2018
@dhaval24 dhaval24 deleted the ImproveAgentLocationFinding branch June 9, 2018 16:22
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants