diff --git a/common/src/test/java/org/wildfly/httpclient/common/HTTPTestServer.java b/common/src/test/java/org/wildfly/httpclient/common/HTTPTestServer.java index 079023d7..3d6a6fef 100644 --- a/common/src/test/java/org/wildfly/httpclient/common/HTTPTestServer.java +++ b/common/src/test/java/org/wildfly/httpclient/common/HTTPTestServer.java @@ -29,6 +29,7 @@ import io.undertow.server.handlers.BlockingHandler; import io.undertow.server.handlers.CanonicalPathHandler; import io.undertow.server.handlers.PathHandler; +import io.undertow.server.handlers.RequestDumpingHandler; import io.undertow.server.handlers.error.SimpleErrorPageHandler; import io.undertow.util.NetworkUtils; import org.junit.runner.Description; @@ -274,6 +275,7 @@ protected HttpHandler getRootHandler() { root = new AuthenticationCallHandler(root); root = new SimpleErrorPageHandler(root); root = new CanonicalPathHandler(root); + root = new RequestDumpingHandler(root); return root; } diff --git a/naming/src/main/java/org/wildfly/httpclient/naming/HttpRemoteNamingService.java b/naming/src/main/java/org/wildfly/httpclient/naming/HttpRemoteNamingService.java index 2f155545..ad977d19 100644 --- a/naming/src/main/java/org/wildfly/httpclient/naming/HttpRemoteNamingService.java +++ b/naming/src/main/java/org/wildfly/httpclient/naming/HttpRemoteNamingService.java @@ -115,21 +115,29 @@ private abstract class NameHandler implements HttpHandler { @Override public final void handleRequest(HttpServerExchange exchange) throws Exception { + HttpNamingClientMessages.MESSAGES.infof("NameHandler: calling handleRequest(%s)", exchange.getRequestPath()); PathTemplateMatch params = exchange.getAttachment(PathTemplateMatch.ATTACHMENT_KEY); String name = URLDecoder.decode(params.getParameters().get(NAME_PATH_PARAMETER), UTF_8.name()); try { + HttpNamingClientMessages.MESSAGES.infof("NameHandler: calling doOperation(name=%s)", name); Object result = doOperation(exchange, name); if (exchange.isComplete()) { + HttpNamingClientMessages.MESSAGES.infof("NameHandler: exchange is complete, returning"); return; } if (result == null) { + HttpNamingClientMessages.MESSAGES.infof("NameHandler: result is null, returning"); exchange.setStatusCode(StatusCodes.OK); } else if (result instanceof Context) { + HttpNamingClientMessages.MESSAGES.infof("NameHandler: result is context, returning"); exchange.setStatusCode(StatusCodes.NO_CONTENT); } else { + HttpNamingClientMessages.MESSAGES.infof("NameHandler: calling doMarshall"); doMarshall(exchange, result); + HttpNamingClientMessages.MESSAGES.infof("NameHandler: called doMarshall"); } } catch (Throwable e) { + HttpNamingClientMessages.MESSAGES.infof("NameHandler: got exception, e = " +e); sendException(exchange, httpServiceConfig, StatusCodes.INTERNAL_SERVER_ERROR, e); } } @@ -268,6 +276,7 @@ public static void sendException(HttpServerExchange exchange, int status, Throwa } public static void sendException(HttpServerExchange exchange, HttpServiceConfig httpServiceConfig, int status, Throwable e) throws IOException { + HttpNamingClientMessages.MESSAGES.infof("HttpRemoteNamingService: sending exceptionto client, e = " + e); HttpServerHelper.sendException(exchange, httpServiceConfig, status, e); } diff --git a/naming/src/main/java/org/wildfly/httpclient/naming/HttpRootContext.java b/naming/src/main/java/org/wildfly/httpclient/naming/HttpRootContext.java index 31b6c6ff..d455bc30 100644 --- a/naming/src/main/java/org/wildfly/httpclient/naming/HttpRootContext.java +++ b/naming/src/main/java/org/wildfly/httpclient/naming/HttpRootContext.java @@ -27,6 +27,7 @@ import org.jboss.marshalling.Marshaller; import org.jboss.marshalling.Marshalling; import org.jboss.marshalling.Unmarshaller; +import org.wildfly.common.annotation.NotNull; import org.wildfly.httpclient.common.HttpMarshallerFactory; import org.wildfly.httpclient.common.HttpTargetContext; import org.wildfly.httpclient.common.WildflyHttpContext; @@ -197,8 +198,11 @@ private static Unmarshaller createUnmarshaller(URI uri, HttpMarshallerFactory ht } private R performWithRetry(NamingOperation function, ProviderEnvironment environment, RetryContext context, Name name, T param) throws NamingException { + + HttpNamingClientMessages.MESSAGES.infof("HttpRootContext: calling performWithRetry"); // Directly pass-through single provider executions if (context == null) { + HttpNamingClientMessages.MESSAGES.infof("HttpRootContext: called peformWithRetry (retryContext == null)"); return function.apply(null, name, param); } @@ -206,6 +210,7 @@ private R performWithRetry(NamingOperation function, ProviderEnviro try { R result = function.apply(context, name, param); environment.dropFromBlocklist(context.currentDestination()); + HttpNamingClientMessages.MESSAGES.infof("HttpRootContext: called peformWithRetry (retryContext != null), notFound = %s", notFound); return result; } catch (NameNotFoundException e) { if (notFound++ > MAX_NOT_FOUND_RETRY) { @@ -253,7 +258,9 @@ private void updateBlocklist(ProviderEnvironment environment, RetryContext conte environment.updateBlocklist(location); } - private Object processInvocation(Name name, HttpString method, String pathSegment) throws NamingException { + private Object processInvocation(@NotNull Name name, @NotNull HttpString method, @NotNull String pathSegment) throws NamingException { + + HttpNamingClientMessages.MESSAGES.infof("HttpRootContext: calling Object processInvocation(name=%s, method=%s, pathSegment=%s)", name, method, pathSegment); ProviderEnvironment environment = httpNamingProvider.getProviderEnvironment(); final RetryContext context = canRetry(environment) ? new RetryContext() : null; return performWithRetry((contextOrNull, name1, param) -> { @@ -287,7 +294,8 @@ private Object processInvocation(Name name, HttpString method, String pathSegmen }, environment, context, name, null); } - private Object performOperation(Name name, URI providerUri, HttpTargetContext targetContext, ClientRequest clientRequest) throws NamingException { + private Object performOperation(@NotNull Name name, @NotNull URI providerUri, @NotNull HttpTargetContext targetContext, @NotNull ClientRequest clientRequest) throws NamingException { + HttpNamingClientMessages.MESSAGES.infof("HttpRootContext: calling Object performOperation(request = %s)", clientRequest); final CompletableFuture result = new CompletableFuture<>(); final ProviderEnvironment providerEnvironment = httpNamingProvider.getProviderEnvironment(); final AuthenticationContext context = providerEnvironment.getAuthenticationContextSupplier().get(); @@ -306,6 +314,7 @@ private Object performOperation(Name name, URI providerUri, HttpTargetContext ta targetContext.sendRequest(clientRequest, sslContext, authenticationConfiguration, null, (input, response, closeable) -> { try { if (response.getResponseCode() == StatusCodes.NO_CONTENT) { + HttpNamingClientMessages.MESSAGES.infof("HttpRootContext.HttpResultHandler: response has no content, completing"); result.complete(new HttpRemoteContext(HttpRootContext.this, name.toString())); IoUtils.safeClose(input); return; @@ -313,6 +322,8 @@ private Object performOperation(Name name, URI providerUri, HttpTargetContext ta httpNamingProvider.performExceptionAction((a, b) -> { + HttpNamingClientMessages.MESSAGES.infof("HttpRootContext.HttpResultHandler: response has content, unmarshalling"); + Exception exception = null; Object returned = null; ClassLoader old = setContextClassLoader(tccl); @@ -336,8 +347,10 @@ private Object performOperation(Name name, URI providerUri, HttpTargetContext ta setContextClassLoader(old); } if (exception != null) { + HttpNamingClientMessages.MESSAGES.infof("HttpRootContext.HttpResultHandler: got exception, completingExceptionally future"); result.completeExceptionally(exception); } else { + HttpNamingClientMessages.MESSAGES.infof("HttpRootContext.HttpResultHandler: got result, completing future"); result.complete(returned); } return null; @@ -370,7 +383,9 @@ private Object performOperation(Name name, URI providerUri, HttpTargetContext ta } - private void processInvocation(Name name, HttpString method, Object object, String pathSegment, Name newName) throws NamingException { + private void processInvocation(@NotNull Name name, @NotNull HttpString method, Object object, @NotNull String pathSegment, Name newName) throws NamingException { + HttpNamingClientMessages.MESSAGES.infof("HttpRootContext: calling void processInvocation(name=%s, method=%s, pathSegment=%s)", + name, method, pathSegment); ProviderEnvironment environment = httpNamingProvider.getProviderEnvironment(); final RetryContext context = canRetry(environment) ? new RetryContext() : null; performWithRetry((contextOrNull, name1, param) -> { @@ -417,7 +432,8 @@ private boolean canRetry(ProviderEnvironment environment) { return environment.getProviderUris().size() > 1; } - private void performOperation(URI providerUri, Object object, HttpTargetContext targetContext, ClientRequest clientRequest) throws NamingException { + private void performOperation(@NotNull URI providerUri, Object object, @NotNull HttpTargetContext targetContext, @NotNull ClientRequest clientRequest) throws NamingException { + HttpNamingClientMessages.MESSAGES.infof("HttpRootContext: calling void performOperation(request = %s)", clientRequest); final CompletableFuture result = new CompletableFuture<>(); final ProviderEnvironment providerEnvironment = httpNamingProvider.getProviderEnvironment(); final AuthenticationContext context = providerEnvironment.getAuthenticationContextSupplier().get(); @@ -444,6 +460,7 @@ private void performOperation(URI providerUri, Object object, HttpTargetContext try { result.complete(null); } finally { + HttpNamingClientMessages.MESSAGES.infof("HttpRootContext: void performOperation(), closing channel"); IoUtils.safeClose(closeable); } }, result::completeExceptionally, null, null); diff --git a/naming/src/test/java/org/wildfly/httpclient/naming/LocalContext.java b/naming/src/test/java/org/wildfly/httpclient/naming/LocalContext.java index d6218faf..da392629 100644 --- a/naming/src/test/java/org/wildfly/httpclient/naming/LocalContext.java +++ b/naming/src/test/java/org/wildfly/httpclient/naming/LocalContext.java @@ -47,13 +47,19 @@ public LocalContext(boolean readOnly) { this.readOnly = readOnly; } + private void dumpContext() { + HttpNamingClientMessages.MESSAGES.infof("dump LocalContext: context = %s", bindings); + } + @Override public Object lookup(Name name) throws NamingException { + dumpContext(); return lookup(name.toString()); } @Override public Object lookup(String name) throws NamingException { + dumpContext(); Object res = bindings.get(name); if (res == null) { throw new NameNotFoundException(); @@ -63,11 +69,13 @@ public Object lookup(String name) throws NamingException { @Override public void bind(Name name, Object obj) throws NamingException { + dumpContext(); bind(name.toString(), obj); } @Override public void bind(String name, Object obj) throws NamingException { + dumpContext(); if (readOnly) { throw new OperationNotSupportedException("bind is read-only"); } @@ -79,11 +87,13 @@ public void bind(String name, Object obj) throws NamingException { @Override public void rebind(Name name, Object obj) throws NamingException { + dumpContext(); rebind(name.toString(), obj); } @Override public void rebind(String name, Object obj) throws NamingException { + dumpContext(); if (readOnly) { throw new OperationNotSupportedException("rebind is read-only"); } @@ -92,11 +102,13 @@ public void rebind(String name, Object obj) throws NamingException { @Override public void unbind(Name name) throws NamingException { + dumpContext(); unbind(name.toString()); } @Override public void unbind(String name) throws NamingException { + dumpContext(); if (readOnly) { throw new OperationNotSupportedException("unbind is read-only"); } @@ -108,11 +120,13 @@ public void unbind(String name) throws NamingException { @Override public void rename(Name oldName, Name newName) throws NamingException { + dumpContext(); rename(oldName.toString(), newName.toString()); } @Override public void rename(String oldName, String newName) throws NamingException { + dumpContext(); if (readOnly) { throw new OperationNotSupportedException("rename is read-only"); } @@ -125,11 +139,13 @@ public void rename(String oldName, String newName) throws NamingException { @Override public NamingEnumeration list(Name name) throws NamingException { + dumpContext(); return list(name.toString()); } @Override public NamingEnumeration list(String name) throws NamingException { + dumpContext(); final Iterator iterator = bindings.keySet().iterator(); return new NamingEnumeration() { public NameClassPair next() { @@ -156,11 +172,13 @@ public NameClassPair nextElement() { @Override public NamingEnumeration listBindings(Name name) throws NamingException { + dumpContext(); return listBindings(name.toString()); } @Override public NamingEnumeration listBindings(String name) throws NamingException { + dumpContext(); final Iterator iterator = bindings.keySet().iterator(); return new NamingEnumeration() { public Binding next() { @@ -187,11 +205,13 @@ public Binding nextElement() { @Override public void destroySubcontext(Name name) throws NamingException { + dumpContext(); destroySubcontext(name.toString()); } @Override public void destroySubcontext(String name) throws NamingException { + dumpContext(); if (readOnly) { throw new OperationNotSupportedException("destroySubcontext is read-only"); } @@ -207,11 +227,13 @@ public void destroySubcontext(String name) throws NamingException { @Override public Context createSubcontext(Name name) throws NamingException { + dumpContext(); return createSubcontext(name.toString()); } @Override public Context createSubcontext(String name) throws NamingException { + dumpContext(); if (readOnly) { throw new OperationNotSupportedException("createSubcontext is read-only"); } @@ -225,6 +247,7 @@ public Context createSubcontext(String name) throws NamingException { @Override public Object lookupLink(Name name) throws NamingException { + dumpContext(); return lookupLink(name.toString()); } diff --git a/naming/src/test/java/org/wildfly/httpclient/naming/ReadOnlyNamingOperationTestCase.java b/naming/src/test/java/org/wildfly/httpclient/naming/ReadOnlyNamingOperationTestCase.java index 5990a095..9c7a902d 100644 --- a/naming/src/test/java/org/wildfly/httpclient/naming/ReadOnlyNamingOperationTestCase.java +++ b/naming/src/test/java/org/wildfly/httpclient/naming/ReadOnlyNamingOperationTestCase.java @@ -62,15 +62,18 @@ public void testReadOnlyBind() throws Exception { @Test public void testReadOnlyReBind() throws Exception { + HttpNamingClientMessages.MESSAGES.info("========= testReadOnlyRebind: start ========="); InitialContext ic = createContext(); try { ic.rebind("name", "value"); Assert.fail("should fail"); } catch (Exception e) { + HttpNamingClientMessages.MESSAGES.info("result: got exception: " + e); Assert.assertTrue(e instanceof NamingException); Assert.assertEquals("rebind is read-only", e.getMessage()); } finally { ic.close(); + HttpNamingClientMessages.MESSAGES.info("========= testReadOnlyRebind: stop ========="); } } diff --git a/naming/src/test/java/org/wildfly/httpclient/naming/SimpleNamingOperationTestCase.java b/naming/src/test/java/org/wildfly/httpclient/naming/SimpleNamingOperationTestCase.java index 7a57456d..360d3c30 100644 --- a/naming/src/test/java/org/wildfly/httpclient/naming/SimpleNamingOperationTestCase.java +++ b/naming/src/test/java/org/wildfly/httpclient/naming/SimpleNamingOperationTestCase.java @@ -56,8 +56,9 @@ public void setup() { HTTPTestServer.registerServicesHandler("naming", new HttpRemoteNamingService(new LocalContext(false), DEFAULT_CLASS_FILTER).createHandler()); } - @Test @Ignore // FIXME WEJBHTTP-37 + @Test //@Ignore // FIXME WEJBHTTP-37 public void testJNDIlookup() throws NamingException { + HttpNamingClientMessages.MESSAGES.info("========= testJNDILookup: start ========="); InitialContext ic = createContext(); Object result = ic.lookup("test"); Assert.assertEquals("test value", result); @@ -68,10 +69,12 @@ public void testJNDIlookup() throws NamingException { Assert.fail(); } catch (NameNotFoundException expected) { } + HttpNamingClientMessages.MESSAGES.info("========= testJNDILookup: stop ========="); } - @Test @Ignore // FIXME WEJBHTTP-37 + @Test //@Ignore // FIXME WEJBHTTP-37 public void testJNDIlookupTimeoutTestCase() throws NamingException, InterruptedException { + HttpNamingClientMessages.MESSAGES.info("========= testJNDILookupTimeoutTestCase: start ========="); InitialContext ic = createContext(); Object result = ic.lookup("test"); Assert.assertEquals("test value", result); @@ -80,10 +83,12 @@ public void testJNDIlookupTimeoutTestCase() throws NamingException, InterruptedE Thread.sleep(1500); result = ic.lookup("comp/UserTransaction"); Assert.assertEquals("transaction", result); + HttpNamingClientMessages.MESSAGES.info("========= testJNDILookupTimeoutTestCase: stop ========="); } @Test public void testJNDIBindings() throws NamingException { + HttpNamingClientMessages.MESSAGES.info("========= testJNDIBindings: start ========="); InitialContext ic = createContext(); try { ic.lookup("bound"); @@ -101,11 +106,13 @@ public void testJNDIBindings() throws NamingException { // Assert.fail(); // } catch (NameNotFoundException e) {} // Assert.assertEquals("test binding 2", ic.lookup("bound2")); + HttpNamingClientMessages.MESSAGES.info("========= testJNDIBindings: stop ========="); } @Test public void testUnmarshallingFilter() throws NamingException { + HttpNamingClientMessages.MESSAGES.info("========= testUnmarshallingFilter: start ========="); InitialContext ic = createContext(); try { ic.lookup("unmarshal"); @@ -128,7 +135,7 @@ public void testUnmarshallingFilter() throws NamingException { } ic.rebind("unmarshal", new IllegalStateException()); Assert.assertEquals(IllegalStateException.class, ic.lookup("unmarshal").getClass()); - + HttpNamingClientMessages.MESSAGES.info("========= testUnmarshallingFilter: start ========="); } private InitialContext createContext() throws NamingException { @@ -140,6 +147,7 @@ private InitialContext createContext() throws NamingException { @Test public void testSimpleUnbind() throws Exception { + HttpNamingClientMessages.MESSAGES.info("========= testSimpleUnbind: start ========="); InitialContext ic = createContext(); Assert.assertEquals("test value", ic.lookup("test").toString()); ic.unbind("test"); @@ -148,10 +156,12 @@ public void testSimpleUnbind() throws Exception { Assert.fail("test is not available anymore"); } catch (NameNotFoundException e) { } + HttpNamingClientMessages.MESSAGES.info("========= testSimpleUnbind: stop ========="); } @Test public void testSimpleSubContext() throws Exception { + HttpNamingClientMessages.MESSAGES.info("========= testSimpleSubContext: start ========="); InitialContext ic = createContext(); ic.createSubcontext("subContext"); Context subContext = (Context)ic.lookup("subContext"); @@ -162,37 +172,52 @@ public void testSimpleSubContext() throws Exception { Assert.fail("subContext is not available anymore"); } catch (NameNotFoundException e) { } + HttpNamingClientMessages.MESSAGES.info("========= testSimpleSubContext: stop ========="); } @Test public void testSimpleRename() throws Exception { + HttpNamingClientMessages.MESSAGES.info("========= testSimpleRename: start ========="); InitialContext ic = createContext(); + HttpNamingClientMessages.MESSAGES.info("=== lookup:"); Assert.assertEquals("test value", ic.lookup("test").toString()); + delay(10) ; + HttpNamingClientMessages.MESSAGES.info("=== rename:"); ic.rename("test", "testB"); + HttpNamingClientMessages.MESSAGES.info("=== relookup:"); + delay(10) ; try { ic.lookup("test"); Assert.fail("test is not available anymore"); } catch (NameNotFoundException e) { + HttpNamingClientMessages.MESSAGES.info("=== result: got exception: " + e); } + delay(10) ; Assert.assertEquals("test value", ic.lookup("testB").toString()); + HttpNamingClientMessages.MESSAGES.info("=== testSimpleRename: stop "); } @Test // WEJBHTTP-69 public void testListCanBeSerialized() throws Exception { + HttpNamingClientMessages.MESSAGES.info("========= testListCanBeSerialized: start ========="); InitialContext ic = createContext(); NamingEnumeration list = ic.list("test"); Assert.assertNotNull(list); + HttpNamingClientMessages.MESSAGES.info("========= testListCanBeSerialized: stop ========="); } @Test // WEJBHTTP-69 public void testListBindingsCanBeSerialized() throws Exception { + HttpNamingClientMessages.MESSAGES.info("========= testBindingsCanBeSerialized: start ========="); InitialContext ic = createContext(); NamingEnumeration list = ic.listBindings("test"); Assert.assertNotNull(list); + HttpNamingClientMessages.MESSAGES.info("========= testBindingsCanBeSerialized: stop ========="); } @Test public void testHttpNamingEjbObjectResolverHelper() throws NamingException { + HttpNamingClientMessages.MESSAGES.info("========= testHttpNamingEjbObjectResolverHelper: start ========="); InitialContext ic = createContext(); Assert.assertEquals(TestHttpNamingEjbObjectResolverHelper.create("readResolve->" + HTTPTestServer.getDefaultServerURL()), ic.lookup("test-resolver-helper")); @@ -200,5 +225,14 @@ public void testHttpNamingEjbObjectResolverHelper() throws NamingException { ic.rebind("test-resolver-helper", TestHttpNamingEjbObjectResolverHelper.create("test")); Assert.assertEquals(TestHttpNamingEjbObjectResolverHelper.create("writeReplace->" + HTTPTestServer.getDefaultServerURL()), ic.lookup("test-resolver-helper")); + HttpNamingClientMessages.MESSAGES.info("========= testHttpNamingEjbObjectResolverHelper: stop ========="); + } + + private void delay(int ms) { + try { + Thread.sleep(ms); + } catch(java.lang.InterruptedException e) { + // noop + } } } diff --git a/pom.xml b/pom.xml index effba884..3c24b0d0 100644 --- a/pom.xml +++ b/pom.xml @@ -47,7 +47,7 @@ 11 11 - 2.2.22.Final + 2.3.7.Final 3.4.1.Final 2.2.1.Final 4.13.1