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

ClassNotFoundException with executable JAR and New Relic agent #1057

Closed
jdpgrailsdev opened this issue Jun 9, 2014 · 13 comments
Closed

ClassNotFoundException with executable JAR and New Relic agent #1057

jdpgrailsdev opened this issue Jun 9, 2014 · 13 comments
Labels
status: invalid An issue that we don't feel is valid

Comments

@jdpgrailsdev
Copy link

When using spring-boot 1.1.0.RC1 in combination with the latest New Relic agent, the application fails to start with ClassNotFoundException errors on start up for classes referenced by the main class. I have done some debugging into the spring-boot-loader code and have determined that there appears to be a class loader issue. Our application is being executed with a command similar to the following:

java -javaagent:newrelic.jar -jar myApplication.jar

where myApplication.jar is a spring-boot repackaged JAR file created by the spring-boot Gradle plugin (i.e. it contains all the necessary dependency JARs packaged inside). When the -javaagent option is not present in the command, the application starts successfully. I attached a remote debugger and determined that the issue/difference is with how the doLoadClass method in org.springframework.boot.loader.LaunchedURLClassLoader behaves. When the New Relic agent is NOT present, the call to return this.rootClassLoader.loadClass(name); throws a ClassNotFoundException, which causes the code to "try to find the class locally", per the comment in that method. When the agent is present, the call to the root class loader returns the main class. This then causes an issue, as the main class's class loader is set to the root class loader and not the LaunchedURLClassLoader instance, which knows about the nested/included JAR files from the application's JAR file. My suspicion is that the agent is causing the main class to get loaded into the root class loader during its instrumentation phase, thus causing it to be returned when attempting to launch the main class via the JarLauncher from the loader. The only work around that I have found is to not use the spring-boot-loader at all and include the dependency JAR's externally to the application JAR and run with both the -javaagent and -classpath options. It should also be noted that I verified that the New Relic agent was not making it into the repackaged JAR and verified that the code in ExecutableArchiveLauncher that prevents the agent from being included in the LaunchedURLClassLoader does appear to work, though does not solve this issue. One final twist: this issue does NOT happen if you launch the application via Gradle with the agent option present in the spring-boot configuration in build.gradle. From what I can tell, this is because launching via the Gradle plugin does not use the spring-boot-loader and its launchers: instead, if uses the Gradle Java execution and launches a new VM with the agent and classpath options. This should probably be changed to use the spring-boot-loader for consistency. Let me know if a sample application would be helpful and I will continue to debug this issue on my end to see if I can gain any additional insight into what is going on.

@philwebb
Copy link
Member

philwebb commented Jun 9, 2014

Do you see the same issue with 1.0.2.RELEASE? I know that new relic worked at one point so I'm trying to figure out when things changed.

@wilkinsona
Copy link
Member

I can't reproduce this using one of Boot's sample apps against either 1.1.0.RC1 or a 1.1.0 snapshot. The New Relic agent does its thing and then the application's main class loads as expected:

java -javaagent:newrelic.jar -jar target/spring-boot-sample-web-freemarker-1.1.0.BUILD-SNAPSHOT.jar
objc[97312]: Class JavaLaunchHelper is implemented in both /Library/Java/JavaVirtualMachines/jdk7/Contents/Home/bin/java and /Library/Java/JavaVirtualMachines/jdk1.7.0_51.jdk/Contents/Home/jre/lib/libinstrument.dylib. One of the two will be used. Which one is undefined.
Jun 9, 2014 16:21:09 +0100 [97312 1] com.newrelic INFO: Agent is using Logback
Jun 9, 2014 16:21:09 +0100 [97312 1] com.newrelic INFO: Loading configuration file "/Users/awilkinson/dev/spring/spring-boot/spring-boot-samples/spring-boot-sample-web-freemarker/./newrelic.yml"

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::  (v1.1.0.BUILD-SNAPSHOT)

2014-06-09 16:21:17.916  INFO 97312 --- [           main] s.f.SampleWebFreeMarkerApplication       : Starting SampleWebFreeMarkerApplication on aw-rmbp.home with PID 97312 (/Users/awilkinson/dev/spring/spring-boot/spring-boot-samples/spring-boot-sample-web-freemarker/target/spring-boot-sample-web-freemarker-1.1.0.BUILD-SNAPSHOT.jar started by awilkinson in /Users/awilkinson/dev/spring/spring-boot/spring-boot-samples/spring-boot-sample-web-freemarker)
2014-06-09 16:21:17.964  INFO 97312 --- [           main] ationConfigEmbeddedWebApplicationContext : Refreshing org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@11f3f414: startup date [Mon Jun 09 16:21:17 BST 2014]; root of context hierarchy
2014-06-09 16:21:19.693  INFO 97312 --- [           main] .t.TomcatEmbeddedServletContainerFactory : Server initialized with port: 8080
…

If you'd like us to look into this some more, a sample application would definitely be helpful. Perhaps there's a difference in the version of the New Relic agent, the JVM or similar? According to the change log in the zip I downloaded, I'm using 3.7.1 of the New Relic agent and I'm running Java 1.7.0_51 on a Mac.

@jdpgrailsdev
Copy link
Author

Let me put together a sample application to at least verify that the issue is reproducible. I did not/have not tried the 1.0.2.RELEASE, which I can also try.

As for the agent, I am also using 3.7.1 and update 55 of Java 1.7 on a Mac.

@jdpgrailsdev
Copy link
Author

After creating a sample Spring-Boot application (version 1.1.0.RC1) that wires up a Java HttpServlet as a Spring bean (and using Jetty as the container), I am not able to reproduce my problem:

Jun 9, 2014 12:47:49 -0400 [3685 1] com.newrelic INFO: Agent is using Logback
Jun 9, 2014 12:47:49 -0400 [3685 1] com.newrelic INFO: Loading configuration file "/Users/jpearlin/Projects/agent/./newrelic.yml"

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::            (v1.1.0.RC1)

2014-06-09 12:47:57.064  INFO 3685 --- [           main] com.test.Application                     : Starting Application with PID 3685 (/Users/jpearlin/Projects/test_app/build/libs/test_app.jar started by jpearlin in /Users/jpearlin/Projects/test_app/build/libs)
2014-06-09 12:47:57.108  INFO 3685 --- [           main] ationConfigEmbeddedWebApplicationContext : Refreshing org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@747e1fd4: startup date [Mon Jun 09 12:47:57 EDT 2014]; root of context hierarchy
2014-06-09 12:47:57.812  INFO 3685 --- [           main] o.s.b.f.s.DefaultListableBeanFactory     : Overriding bean definition for bean 'beanNameViewResolver': replacing [Root bean: class [null]; scope=; abstract=false; lazyInit=false; autowireMode=3; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=org.springframework.boot.autoconfigure.web.ErrorMvcAutoConfiguration$WhitelabelErrorViewConfiguration; factoryMethodName=beanNameViewResolver; initMethodName=null; destroyMethodName=(inferred); defined in class path resource [org/springframework/boot/autoconfigure/web/ErrorMvcAutoConfiguration$WhitelabelErrorViewConfiguration.class]] with [Root bean: class [null]; scope=; abstract=false; lazyInit=false; autowireMode=3; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=org.springframework.boot.autoconfigure.web.WebMvcAutoConfiguration$WebMvcAutoConfigurationAdapter; factoryMethodName=beanNameViewResolver; initMethodName=null; destroyMethodName=(inferred); defined in class path resource [org/springframework/boot/autoconfigure/web/WebMvcAutoConfiguration$WebMvcAutoConfigurationAdapter.class]]
2014-06-09 12:47:58.632  INFO 3685 --- [           main] e.j.JettyEmbeddedServletContainerFactory : Server initialized with port: 8080
2014-06-09 12:47:58.637  INFO 3685 --- [           main] org.eclipse.jetty.server.Server          : jetty-8.1.14.v20131031
2014-06-09 12:47:58.688  INFO 3685 --- [           main] /                                        : Initializing Spring embedded WebApplicationContext
2014-06-09 12:47:58.688  INFO 3685 --- [           main] o.s.web.context.ContextLoader            : Root WebApplicationContext: initialization completed in 1582 ms
2014-06-09 12:47:59.342  INFO 3685 --- [           main] o.s.b.c.e.ServletRegistrationBean        : Mapping servlet: 'testServlet' to [/test]
2014-06-09 12:47:59.344  INFO 3685 --- [           main] o.s.b.c.e.ServletRegistrationBean        : Mapping servlet: 'dispatcherServlet' to [/]
2014-06-09 12:47:59.346  INFO 3685 --- [           main] o.s.b.c.embedded.FilterRegistrationBean  : Mapping filter: 'hiddenHttpMethodFilter' to: [/*]
2014-06-09 12:47:59.367  INFO 3685 --- [           main] o.e.jetty.server.AbstractConnector       : Started SelectChannelConnector@0.0.0.0:8080
2014-06-09 12:47:59.512  INFO 3685 --- [           main] o.s.w.s.handler.SimpleUrlHandlerMapping  : Mapped URL path [/**/favicon.ico] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2014-06-09 12:47:59.613  INFO 3685 --- [           main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/error],methods=[],params=[],headers=[],consumes=[],produces=[],custom=[]}" onto public org.springframework.http.ResponseEntity<java.util.Map<java.lang.String, java.lang.Object>> org.springframework.boot.autoconfigure.web.BasicErrorController.error(javax.servlet.http.HttpServletRequest)
2014-06-09 12:47:59.614  INFO 3685 --- [           main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/error],methods=[],params=[],headers=[],consumes=[],produces=[text/html],custom=[]}" onto public org.springframework.web.servlet.ModelAndView org.springframework.boot.autoconfigure.web.BasicErrorController.errorHtml(javax.servlet.http.HttpServletRequest)
2014-06-09 12:47:59.635  INFO 3685 --- [           main] o.s.w.s.handler.SimpleUrlHandlerMapping  : Mapped URL path [/**] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2014-06-09 12:47:59.636  INFO 3685 --- [           main] o.s.w.s.handler.SimpleUrlHandlerMapping  : Mapped URL path [/webjars/**] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2014-06-09 12:47:59.859  INFO 3685 --- [           main] o.s.j.e.a.AnnotationMBeanExporter        : Registering beans for JMX exposure on startup
2014-06-09 12:47:59.902  INFO 3685 --- [           main] /                                        : Initializing Spring FrameworkServlet 'dispatcherServlet'
2014-06-09 12:47:59.902  INFO 3685 --- [           main] o.s.web.servlet.DispatcherServlet        : FrameworkServlet 'dispatcherServlet': initialization started
2014-06-09 12:47:59.928  INFO 3685 --- [           main] o.s.web.servlet.DispatcherServlet        : FrameworkServlet 'dispatcherServlet': initialization completed in 26 ms
2014-06-09 12:47:59.971  INFO 3685 --- [           main] o.e.jetty.server.AbstractConnector       : Started SelectChannelConnector@0.0.0.0:8080
2014-06-09 12:47:59.996  INFO 3685 --- [           main] .s.b.c.e.j.JettyEmbeddedServletContainer : Jetty started on port: 8080
2014-06-09 12:47:59.997  INFO 3685 --- [           main] com.test.Application                     : Started Application in 3.406 seconds (JVM running for 11.196)

I am not exactly sure what is different from the application that is experiencing the issue (other than the inclusion of a few more dependencies used for compilation). It certainly doesn't explain the behavior I am seeing when attaching the remote debugger with regards to the class loaders. I will continue to dig on my end, but any pointers/leads with regards to what could be impacting the class loader delegation when running with the spring-boot-loader would be greatly appreciated.

@philwebb
Copy link
Member

philwebb commented Jun 9, 2014

Did you try the 1.0.2 version with your original application? Some logic has changed with ExecutableArchiveLauncher (specifically around the createClassLoader method) which might be a place to start.

@jdpgrailsdev
Copy link
Author

I tried 1.0.2, but get the same issue:

java.lang.reflect.InvocationTargetException
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:53)
    at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.NoClassDefFoundError: org/springframework/boot/SpringApplication
    at com.test.Application.main(Application.java:12)
    ... 6 more
Caused by: java.lang.ClassNotFoundException: org.springframework.boot.SpringApplication
    at java.net.URLClassLoader$1.run(URLClassLoader.java:366)
    at java.net.URLClassLoader$1.run(URLClassLoader.java:355)
    at java.security.AccessController.doPrivileged(Native Method)
    at java.net.URLClassLoader.findClass(URLClassLoader.java:354)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:425)
    at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:308)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:358)
    ... 7 more

So there are two weird things that happen. First, I created another sample application and cannot for the life of me to get it to cause the same error as above. I slowly started adding dependencies and source to the test application from the one that is failing and it still starts as expected. The second odd thing is that when I remove the -javaagent arg from the application that does exhibit the error above, it starts fine, still leading me to believe its some sort of weird class loader/agent/instrumentation edge case. I have confirmed that all of the spring-boot-loader classes have been copied into the executable JAR file and that all the proper spring-boot dependency JAR files are present in the repackaged JAR file as well. I'm going to keep digging.

@jdpgrailsdev
Copy link
Author

I have narrowed this down a bit (I think). I cloned the project that is having the issue above and stripped it down to just have an empty Spring config and simple main method in the main class launched by Spring. When I do this in the test application, it starts up fine, even with the Java agent present. When I do this with the cloned application (with no dependencies, other than the ones required to run Spring-Boot and Jetty), it fails with the error above. On a whim, I decided to remove all of the Eclipse metadata, Gradle metdata and other non-Spring-Boot related files stored in the project (the New Relic agent YAML file, some other files used to deploy with Docker, etc). I am almost positive that these files are NOT making it on to the classpath or in to the repackaged JAR (as I do not seem them in there when I expand the JAR file). However, when I remove them from my source tree (and get rid of the task that copies them around in to the ZIP file I am building), the application starts up with the agent present. I am manually copying the New Relic YAML file into place after expanding the ZIP which contains the New Relic agent and the repackaged JAR file. I am starting to think that some magic is causing these extra files to be picked up by Spring-Boot and is causing it to choke because they are not something it can handle. Is this even possible? I know that you can use YAML configuration files with Spring-Boot, but I thought they either had to be on the classpath or in a specified location (e.g. it does not just scan for every YAML file around). I am going to see if I can further pin this down, but it seems to have something to do with the presence of these non-Spring-Boot files being around/copied at distribution time.

@philwebb
Copy link
Member

philwebb commented Jun 9, 2014

If the SpringApplication class is not even loaded then I doubt the YAML file processing is kicking in. Could it be something specific to the new relic configuration? Are you running the exact same jar when you are testing with and without the agent? Perhaps try moving the jar to an empty folder to see if it is a problem with the jar or the folder that the jar is in.

One other thing to check is that the JAR itself has not been recompressed at all during your zip processing. Nested JAR entries need to be stored uncompressed so that we can seek into them. (see http://docs.spring.io/spring-boot/docs/current/reference/htmlsingle/#executable-jar-zip-entry-compression). Although I think you would see a different error if it was a compression problem.

@jdpgrailsdev
Copy link
Author

I don't think the compression is the issue. If I build the JAR and zip it and the New Relic agent jar up together, then unzip it and run it works:

jpearlin@jpearlin-mbp:~/Projects/broken_app/build/distributions$ java -javaagent:agent/newrelic.jar -jar libs/broken_test_app.jar
objc[1439]: Class JavaLaunchHelper is implemented in both /Library/Java/JavaVirtualMachines/jdk1.7.0_55.jdk/Contents/Home/bin/java and /Library/Java/JavaVirtualMachines/jdk1.7.0_55.jdk/Contents/Home/jre/lib/libinstrument.dylib. One of the two will be used. Which one is undefined.
Jun 10, 2014 09:36:29 -0400 [1439 1] com.newrelic INFO: Agent is using Logback
Jun 10, 2014 09:36:29 -0400 [1439 1] com.newrelic INFO: Loading configuration file "/Users/jpearlin/Projects/broken_app/build/distributions/agent/./newrelic.yml"

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::            (v1.1.0.RC1)

2014-06-10 09:36:37.199  INFO 1439 --- [           main] com.test.broken.Application              : Starting Application on jpearlin-mbp with PID 1439 (/Users/jpearlin/Projects/broken_app/build/distributions/libs/broken_test_app.jar started by jpearlin in /Users/jpearlin/Projects/broken_app/build/distributions)
2014-06-10 09:36:37.237  INFO 1439 --- [           main] ationConfigEmbeddedWebApplicationContext : Refreshing org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@12b327ee: startup date [Tue Jun 10 09:36:37 EDT 2014]; root of context hierarchy
2014-06-10 09:36:37.948  INFO 1439 --- [           main] o.s.b.f.s.DefaultListableBeanFactory     : Overriding bean definition for bean 'beanNameViewResolver': replacing [Root bean: class [null]; scope=; abstract=false; lazyInit=false; autowireMode=3; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=org.springframework.boot.autoconfigure.web.ErrorMvcAutoConfiguration$WhitelabelErrorViewConfiguration; factoryMethodName=beanNameViewResolver; initMethodName=null; destroyMethodName=(inferred); defined in class path resource [org/springframework/boot/autoconfigure/web/ErrorMvcAutoConfiguration$WhitelabelErrorViewConfiguration.class]] with [Root bean: class [null]; scope=; abstract=false; lazyInit=false; autowireMode=3; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=org.springframework.boot.autoconfigure.web.WebMvcAutoConfiguration$WebMvcAutoConfigurationAdapter; factoryMethodName=beanNameViewResolver; initMethodName=null; destroyMethodName=(inferred); defined in class path resource [org/springframework/boot/autoconfigure/web/WebMvcAutoConfiguration$WebMvcAutoConfigurationAdapter.class]]
2014-06-10 09:36:38.738  INFO 1439 --- [           main] e.j.JettyEmbeddedServletContainerFactory : Server initialized with port: 8080
2014-06-10 09:36:38.744  INFO 1439 --- [           main] org.eclipse.jetty.server.Server          : jetty-9.0.3.v20130506
2014-06-10 09:36:38.786  INFO 1439 --- [           main] /                                        : Initializing Spring embedded WebApplicationContext
2014-06-10 09:36:38.786  INFO 1439 --- [           main] o.s.web.context.ContextLoader            : Root WebApplicationContext: initialization completed in 1552 ms
2014-06-10 09:36:39.421  INFO 1439 --- [           main] o.s.b.c.e.ServletRegistrationBean        : Mapping servlet: 'dispatcherServlet' to [/]
2014-06-10 09:36:39.425  INFO 1439 --- [           main] o.s.b.c.embedded.FilterRegistrationBean  : Mapping filter: 'hiddenHttpMethodFilter' to: [/*]
2014-06-10 09:36:39.428  INFO 1439 --- [           main] o.e.jetty.server.handler.ContextHandler  : Started o.s.b.c.e.j.JettyEmbeddedWebAppContext@797f8b39{/,null,AVAILABLE}
2014-06-10 09:36:39.461  INFO 1439 --- [           main] o.eclipse.jetty.server.ServerConnector   : Started ServerConnector@82df887{HTTP/1.1}{0.0.0.0:8080}
2014-06-10 09:36:39.468  INFO 1439 --- [           main] o.eclipse.jetty.server.ServerConnector   : Stopped ServerConnector@82df887{HTTP/1.1}{0.0.0.0:8080}
2014-06-10 09:36:39.588  INFO 1439 --- [           main] o.s.w.s.handler.SimpleUrlHandlerMapping  : Mapped URL path [/**/favicon.ico] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2014-06-10 09:36:39.691  INFO 1439 --- [           main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/error],methods=[],params=[],headers=[],consumes=[],produces=[],custom=[]}" onto public org.springframework.http.ResponseEntity<java.util.Map<java.lang.String, java.lang.Object>> org.springframework.boot.autoconfigure.web.BasicErrorController.error(javax.servlet.http.HttpServletRequest)
2014-06-10 09:36:39.691  INFO 1439 --- [           main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/error],methods=[],params=[],headers=[],consumes=[],produces=[text/html],custom=[]}" onto public org.springframework.web.servlet.ModelAndView org.springframework.boot.autoconfigure.web.BasicErrorController.errorHtml(javax.servlet.http.HttpServletRequest)
2014-06-10 09:36:39.713  INFO 1439 --- [           main] o.s.w.s.handler.SimpleUrlHandlerMapping  : Mapped URL path [/**] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2014-06-10 09:36:39.713  INFO 1439 --- [           main] o.s.w.s.handler.SimpleUrlHandlerMapping  : Mapped URL path [/webjars/**] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2014-06-10 09:36:39.979  INFO 1439 --- [           main] o.s.j.e.a.AnnotationMBeanExporter        : Registering beans for JMX exposure on startup
2014-06-10 09:36:40.049  INFO 1439 --- [           main] /                                        : Initializing Spring FrameworkServlet 'dispatcherServlet'
2014-06-10 09:36:40.049  INFO 1439 --- [           main] o.s.web.servlet.DispatcherServlet        : FrameworkServlet 'dispatcherServlet': initialization started
2014-06-10 09:36:40.074  INFO 1439 --- [           main] o.s.web.servlet.DispatcherServlet        : FrameworkServlet 'dispatcherServlet': initialization completed in 25 ms
2014-06-10 09:36:40.076  INFO 1439 --- [           main] o.eclipse.jetty.server.ServerConnector   : Started ServerConnector@82df887{HTTP/1.1}{0.0.0.0:8080}
2014-06-10 09:36:40.081  INFO 1439 --- [           main] .s.b.c.e.j.JettyEmbeddedServletContainer : Jetty started on port: 8080
2014-06-10 09:36:40.082  INFO 1439 --- [           main] com.test.broken.Application              : Started Application in 3.33 seconds (JVM running for 10.952)

I am going to try adding in one by one the other files that are being included in the ZIP to see if I can determine when it stops working (I suppose it still could be a compression issue, as that would change as more and more files are added -- especially text based files that can become highly compressed).

@jdpgrailsdev
Copy link
Author

I think that I have ruled out compression as the culprit. I changed my Gradle script to built a .tar file instead and from the Gradle docs, the compression for the Tar task is turned off by default: http://www.gradle.org/docs/current/dsl/org.gradle.api.tasks.bundling.Tar.html#org.gradle.api.tasks.bundling.Tar:compression.

I have also ruled out the presence of the config files/non-source files in the ZIP/TAR as the culprit. I added them to the project that starts up correctly and it did not have an impact.

As far as I can tell, I have two identical projects: one that loads just fine with the New Relic agent active and one that fails with the ClassNotFoundException. Both are being bundled into an archive (ZIP or TAR, doesn't seem to matter). There are really only three differences between two:

  1. The project that fails to start has Eclipse metadata files present, which I have verified are not leaking into the ZIP/TAR or the repackaged JAR file.
  2. The project that fails to start originally got its dependencies from an internal repository (possible that there is a bogus JAR/dependency in our internally hosted Maven repo).
  3. The project that fails to start is managed by Git, though none of the Git files are making it into the archive/repackaged JAR.

I'm going to investigate #2 a bit more to see if there is in fact a bogus dependency on the class-path that is causing the issue, as at this point, I do not see really any other differences between the project that works and the one that does not work.

@jdpgrailsdev
Copy link
Author

So, I think that I just lead everyone on a wild goose chase. The issue appears to be with using the com.newrelic namespace for a package in combination with Spring-Boot and the New Relic agent. What is interesting is that if I do NOT use the Spring-Boot repackaged JAR, the New Relic agent does not cause any issue when instrumenting code in the com.newrelic package space. Therefore, there is definitely some interplay between the agent and the Spring-Boot launcher/custom class-loader that is getting fouled up when the package to be instrumented begins with com.newrelic. Therefore, I am not sure if this is exposing a larger issue with Java agents/load-time weaving and the custom class loader infrastructure in Spring-Boot or is such a wild edge case that its not worth further investigation. In the meantime, I will just rename my packages to avoid the issue with the ClassNotFoundException on start up.

@philwebb
Copy link
Member

Wow! Sounds like that was a pain to track down. It's worth knowing about the restriction but I don't think we need to change anything from our end. Hopefully this bug report will help anyone in the future that happens to hit the same issue.

@alylad
Copy link

alylad commented Jan 20, 2017

This is old but just stumbled across it. School boy error. I managed to modify the executable jar from underneath the running application. This corrupted it, and caused the same ClassNotFound

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
status: invalid An issue that we don't feel is valid
Projects
None yet
Development

No branches or pull requests

4 participants