HotswapProjects / HotswapAgent

Java unlimited redefinition of classes at runtime.
GNU General Public License v2.0
2.37k stars 493 forks source link

Issue with using HotSwapAgent with Jersey2 endpoints with some injections in it #185

Open dmitry-zhuravlev opened 7 years ago

dmitry-zhuravlev commented 7 years ago

Tried to use HotSwapAgent with DCEVM light for SDK 8u112 with Payara 4.1.1.162 server. I have some Jersey 2 endpoins with some injections via @Inject. During reload I got several:

[2017-03-17T17:08:33.170+0300] [Payara 4.1] [INFO] [] [] [tid: _ThreadID=6 _ThreadName=JDWP Transport Listener: dt_socket] [timeMillis: 1489759713170] [levelValue: 800] [[
  HOTSWAP AGENT: 17:08:33.096 ERROR (org.hotswap.agent.annotation.handler.PluginClassFileTransformer) - InvocationTargetException in transform method on plugin 'class org.hotswap.agent.plugin.proxy.ProxyPlugin' class 'com/test/StatusEndpoint'.
java.lang.reflect.InvocationTargetException
    at sun.reflect.GeneratedMethodAccessor93.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.hotswap.agent.annotation.handler.PluginClassFileTransformer.transform(PluginClassFileTransformer.java:189)
    at org.hotswap.agent.annotation.handler.PluginClassFileTransformer.transform(PluginClassFileTransformer.java:85)
    at org.hotswap.agent.util.HotswapTransformer.transform(HotswapTransformer.java:172)
    at sun.instrument.TransformerManager.transform(TransformerManager.java:188)
    at sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:428)
Caused by: java.lang.IllegalStateException: This web container has not yet been started
    at org.glassfish.web.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1686)
    at org.glassfish.web.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1645)
    at org.hotswap.agent.plugin.proxy.hscglib.GeneratorParametersTransformer.getGeneratorParamsMap(GeneratorParametersTransformer.java:82)
    at org.hotswap.agent.plugin.proxy.hscglib.GeneratorParametersTransformer.getGeneratorParams(GeneratorParametersTransformer.java:110)
    at org.hotswap.agent.plugin.proxy.ProxyPlugin.transformCglibProxy(ProxyPlugin.java:106)
    ... 8 more]]

When I tried to reach the given endpoint the Payara throw exception like:

[2017-03-17T15:13:32.958+0300] [Payara 4.1] [WARNING] [] [javax.enterprise.web] [tid: _ThreadID=84 _ThreadName=http-listener-1(1)] [timeMillis: 1489752812958] [levelValue: 900] [[
  StandardWrapperValve[com.test.application.EndpointConfiguration]: Servlet.service() for servlet com.test.application.EndpointConfiguration threw exception
org.glassfish.hk2.api.UnsatisfiedDependencyException: There was no object available for injection at SystemInjecteeImpl(requiredType=HealthCheckRegistryInitializer,parent=StatusEndpoint,qualifiers={},position=-1,optional=false,self=false,unqualified=null,1904088892)
    at org.jvnet.hk2.internal.ThreeThirtyResolver.resolve(ThreeThirtyResolver.java:75)
    at org.jvnet.hk2.internal.ClazzCreator.resolve(ClazzCreator.java:211)
    at org.jvnet.hk2.internal.ClazzCreator.resolveAllDependencies(ClazzCreator.java:234)
    at org.jvnet.hk2.internal.ClazzCreator.create(ClazzCreator.java:357)
    at org.jvnet.hk2.internal.SystemDescriptor.create(SystemDescriptor.java:471)
    at org.jvnet.hk2.internal.SingletonContext$1.compute(SingletonContext.java:83)
    at org.jvnet.hk2.internal.SingletonContext$1.compute(SingletonContext.java:71)
    at org.glassfish.hk2.utilities.cache.Cache$OriginThreadAwareFuture$1.call(Cache.java:97)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at org.glassfish.hk2.utilities.cache.Cache$OriginThreadAwareFuture.run(Cache.java:154)
    at org.glassfish.hk2.utilities.cache.Cache.compute(Cache.java:199)
    at org.jvnet.hk2.internal.SingletonContext.findOrCreate(SingletonContext.java:122)
    at org.jvnet.hk2.internal.Utilities.createService(Utilities.java:2022)
    at org.jvnet.hk2.internal.ServiceLocatorImpl.internalGetService(ServiceLocatorImpl.java:766)
    at org.jvnet.hk2.internal.ServiceLocatorImpl.getService(ServiceLocatorImpl.java:705)
    at org.glassfish.jersey.internal.inject.Injections.getOrCreate(Injections.java:172)
    at org.glassfish.jersey.server.model.MethodHandler$ClassBasedMethodHandler.getInstance(MethodHandler.java:284)
    at org.glassfish.jersey.server.internal.routing.PushMethodHandlerRouter.apply(PushMethodHandlerRouter.java:74)

So the injection of HealthCheckRegistryInitializer to StatusEndpoint failed. The same situation happened if I have @Interceptors definition on top of StatusEndpoint.

However if I have a plain Jersey 2 endpoint without any @Interceptors and @Inject the hot swap completes successfully.

skybber commented 7 years ago

Thanks for feedback. We're working on Payara support now and I've already noticed the first exception, I ignored it in my test project and hotswap works. The source of this problem looks clear, HA registers WebappClassLoader but it has not been started yet.

skybber commented 7 years ago

There is new fix for first issue, the next one requires much more work. I don't use hk2, any volunteer?

dmitry-zhuravlev commented 7 years ago

Thank you for quick fix the part of the problem. Also I noticed that restart of Jersey container doesn't work in case if I add a new injectee to the Jersey endpoint. After the HotSwap I got:

  HOTSWAP AGENT: 15:14:07.834 ERROR (org.hotswap.agent.plugin.jersey2.Jersey2Plugin) - Error reloading Jersey Container.
java.lang.reflect.InvocationTargetException
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.hotswap.agent.plugin.jersey2.Jersey2Plugin$1.executeCommand(Jersey2Plugin.java:143)
    at org.hotswap.agent.command.impl.CommandExecutor.run(CommandExecutor.java:25)
Caused by: java.lang.IllegalStateException: ServiceLocatorImpl(__HK2_Generated_3,6,1445086820) has been shut down
    at org.jvnet.hk2.internal.ServiceLocatorImpl.checkState(ServiceLocatorImpl.java:2318)
    at org.jvnet.hk2.internal.ServiceLocatorImpl.preDestroy(ServiceLocatorImpl.java:1026)
    at org.jvnet.hk2.internal.ServiceLocatorImpl.preDestroy(ServiceLocatorImpl.java:1018)
    at org.glassfish.jersey.server.ApplicationHandler.onShutdown(ApplicationHandler.java:1200)
    at org.glassfish.jersey.servlet.ServletContainer.reload(ServletContainer.java:618)
    at org.glassfish.jersey.servlet.ServletContainer.reload(ServletContainer.java:612)
    ... 6 more]]

Probably the hk2 should be somehow restarted together with Jersey container....

skybber commented 7 years ago

Are you using HotswapAgent v1.0 or v1.1 at least ? According line numbers (Jersey2Plugin.java:143) you have some old one...

dmitry-zhuravlev commented 7 years ago

I tried on 1.0 and also with the latest builded SNAPSHOT version from yesterday.

skybber commented 7 years ago

Ok, then you supply wrong stack trace, look at line 143: https://github.com/HotswapProjects/HotswapAgent/blob/master/plugin/hotswap-agent-jersey2-plugin/src/main/java/org/hotswap/agent/plugin/jersey2/Jersey2Plugin.java#L143

In the latest version your call should be from this line (anonymous class): https://github.com/HotswapProjects/HotswapAgent/blob/master/plugin/hotswap-agent-jersey2-plugin/src/main/java/org/hotswap/agent/plugin/jersey2/Jersey2Plugin.java#L173

dmitry-zhuravlev commented 7 years ago

Yep, you are right. I have the old one in "glassfish\domains\domain1\lib\ext\" Tried to test it with release version 1.0 and I have no "Error reloading Jersey Container". At least yet :)

dmitry-zhuravlev commented 7 years ago

@skybber But I think that issue should not be closed until the UnsatisfiedDependencyException for hk2 will be resolved... Or there is another issue for that?

dmitry-zhuravlev commented 7 years ago

Probably this one already opened: #191

skybber commented 7 years ago

Could you provide StatutEndpoint class? We should probably extend reload triggers in appropriate code in JerseyPlugin

dmitry-zhuravlev commented 7 years ago

import logging.LoggingContextAroundInvokeInterceptor;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import status.v1.control.health.util.HealthAggregation;
import status.v1.control.health.util.HealthCheckRegistry;
import status.v1.control.health.util.HealthCheckRegistryInitializer;
import io.swagger.annotations.Api;
import io.swagger.annotations.ApiOperation;
import io.swagger.annotations.ApiResponse;
import io.swagger.annotations.ApiResponses;

import javax.inject.Inject;
import javax.inject.Singleton;
import javax.interceptor.Interceptors;
import javax.ws.rs.GET;
import javax.ws.rs.Path;
import javax.ws.rs.Produces;
import javax.ws.rs.QueryParam;
import javax.ws.rs.core.MediaType;
import javax.ws.rs.core.Response;

@Singleton
@Api(value = "/" + StatusConstants.REST_RESOURCE_NAME, tags = {"status", })
@Path(StatusConstants.ENDPOINT_PATH)
@Interceptors(LoggingContextAroundInvokeInterceptor.class)
public class StatusEndpoint {
    private static final Logger LOG = LoggerFactory.getLogger(StatusEndpoint.class);

    @Inject
    private HealthCheckRegistryInitializer healthCheckRegistryInitializer;

    public StatusEndpoint() {
        super();
    }

    @Path("/ping")
    @GET
    @Produces(MediaType.TEXT_PLAIN)
    @ApiOperation(value = "Ping the service with a defined payload", response = String.class, tags = "Status")
    @ApiResponses(value = { @ApiResponse(code = 200, message = "", response = String.class),
            @ApiResponse(code = 400, message = "Bad request."),
            @ApiResponse(code = 404, message = "Resource not available."),
            @ApiResponse(code = 500, message = "Internal server error."), })
    public Response ping(@QueryParam("echo") final String payload) {
        LOG.info("Ping called, payload is: {}", payload);
        return Response.ok(payload).build();
    }

    @Path("/health")
    @GET
    @Produces(MediaType.APPLICATION_JSON)
    @ApiOperation(value = "Check health of the service", response = HealthAggregation.class, tags = "Status")
    @ApiResponses(value = { @ApiResponse(code = 200, message = "", response = HealthAggregation.class),
            @ApiResponse(code = 400, message = "Bad request."),
            @ApiResponse(code = 404, message = "Resource not available."),
            @ApiResponse(code = 500, message = "Internal server error."), })
    public Response getHealthStatus() {
        LOG.info("The health status has been requested");
        final HealthCheckRegistry healthCheckRegistry = this.healthCheckRegistryInitializer.getHealthCheckRegistry();
        return Response.ok(HealthAggregation.aggregate(healthCheckRegistry.runHealthChecks())).build();
    }
}
skybber commented 7 years ago

Are you using plain HK2 or some bridged external DI library like Guice?

dmitry-zhuravlev commented 7 years ago

In this particular case it is HK2 DI.

skybber commented 7 years ago

I have tested HK2 injection on simple hotswap project. If I change injection points, the hotswap works. Could you create minimalistic example to reproduce your problem?

dmitry-zhuravlev commented 7 years ago

Here is an example which I have made: https://github.com/dmitry-zhuravlev/HotswapAgentExamples/tree/payara-jersey2/payara-jersey2 To reproduce the mentioned problem do the following: 1) Deploy to Payara (GlassFish 4.1.1.162). Probably other versions will be also fine. 2) Execute REST call to http://localhost:8080/payara-jersey2/services/service1 and it should be 200 OK 3) With enabled HotSwapAgent try to comment out inject of service2 and make a hotswap. 4) In the result the response will be 500 (Internal server Error) with some org.glassfish.hk2.api.UnsatisfiedDependencyException in the stacktrace.

skybber commented 7 years ago

Thanks for example. Looks there is glassfish specific problem with Jersey2/HK2 reloading.

bseiller commented 6 years ago

Since we had the same error (org.glassfish.hk2.api.UnsatisfiedDependencyException) under Glassfish 4.1, build 13 we tested with the latest/last 4.1 version of Payara (4.1.2.181). Apart the info/warnings that are also mentioned here by Edilmar Alves https://blog.payara.fish/using-hotswapagent-to-speed-up-development reloading worked at intended - so it seems the culprit was the Jersey2 version that came with early Glassfish 4.1

Following the mentioned info/warning during startup for the sake of completeness - if necessary we can provide the full stacktraces

[2018-06-05T14:49:39.938+0200] [Payara 4.1] [INFORMATION] [] [] [tid: _ThreadID=31_ThreadName=RunLevelControllerThread-1528202978689] [timeMillis: 1528202979938] [levelValue: 800] [[ HOTSWAP AGENT: 14:49:39.937 ERROR (org.hotswap.agent.annotation.handler.PluginClassFileTransformer) - InvocationTargetException in transform method on plugin 'class org.hotswap.agent.plugin.hibernate.HibernatePlugin' class 'org/hibernate/validator/internal/metadata/BeanMetaDataManager'.`
...
Caused by: compile error: no such class: org.hotswap.agent.config.PluginManager

[2018-06-05T14:49:39.947+0200] [Payara 4.1] [INFORMATION] [] [] [tid: _ThreadID=31 _ThreadName=RunLevelControllerThread-1528202978689] [timeMillis: 1528202979947] [levelValue: 800] [[HOTSWAP AGENT: 14:49:39.947 ERROR (org.hotswap.agent.annotation.handler.PluginClassFileTransformer) - InvocationTargetException in transform method on plugin 'class org.hotswap.agent.plugin.hibernate.HibernatePlugin' class 'org/hibernate/validator/internal/metadata/provider/AnnotationMetaDataProvider'.
...
[2018-06-05T14:49:40.235+0200] [Payara 4.1] [INFORMATION] [] [] [tid: _ThreadID=30 _ThreadName=RunLevelControllerThread-1528202978689] [timeMillis: 1528202980235] [levelValue: 800] [[  HOTSWAP AGENT: 14:49:40.234 ERROR (org.hotswap.agent.annotation.handler.PluginClassFileTransformer) - InvocationTargetException in transform method on plugin 'class org.hotswap.agent.plugin.tomcat.TomcatPlugin' class 'org/apache/catalina/loader/WebappLoader'.
...
[2018-06-05T14:49:40.437+0200] [Payara 4.1] [INFORMATION] [] [] [tid: _ThreadID=30 _ThreadName=RunLevelControllerThread-1528202978689] [timeMillis: 1528202980437] [levelValue: 800] [[  HOTSWAP AGENT: 14:49:40.436 ERROR (org.hotswap.agent.annotation.handler.PluginClassFileTransformer) - InvocationTargetException in transform method on plugin 'class org.hotswap.agent.plugin.tomcat.TomcatPlugin' class 'org/apache/naming/resources/ProxyDirContext'.
...
[2018-06-05T14:50:21.957+0200] [Payara 4.1] [INFORMATION] [] [] [tid: _ThreadID=61 _ThreadName=admin-thread-pool::admin-listener(2)] [timeMillis: 1528203021957] [levelValue: 800] [[  HOTSWAP AGENT: 14:50:21.957 ERROR org.hotswap.agent.annotation.handler.PluginClassFileTransformer) - InvocationTargetException in transform method on plugin 'class org.hotswap.agent.plugin.elresolver.ELResolverPlugin' class 'javax/el/BeanELResolver'.