This is an automated email from the ASF dual-hosted git repository. sergeychugunov pushed a commit to branch master in repository https://gitbox.apache.org/repos/asf/ignite.git
The following commit(s) were added to refs/heads/master by this push: new 6c04182 IGNITE-15225 Improve logging of the peer class loading error message - Fixes #9293. 6c04182 is described below commit 6c04182ea64f2f68221a41a550dd394a93a7aa89 Author: denis-chudov <moongll...@gmail.com> AuthorDate: Tue Aug 10 17:50:15 2021 +0300 IGNITE-15225 Improve logging of the peer class loading error message - Fixes #9293. Signed-off-by: Sergey Chugunov <sergey.chugu...@gmail.com> --- .../deployment/GridDeploymentClassLoader.java | 208 ++++++++++++--------- .../deployment/GridDeploymentCommunication.java | 189 +++++++++++-------- .../ignite/internal/util/GridLogThrottle.java | 13 ++ .../internal/TestRecordingCommunicationSpi.java | 2 +- ...loymentRequestOfUnknownClassProcessingTest.java | 4 +- .../ClassLoadingProblemExtendedLoggingTest.java | 178 ++++++++++++++++++ .../apache/ignite/tests/p2p/P2PTestPredicate.java | 1 - .../testsuites/IgniteUriDeploymentTestSuite.java | 2 + 8 files changed, 430 insertions(+), 167 deletions(-) diff --git a/modules/core/src/main/java/org/apache/ignite/internal/managers/deployment/GridDeploymentClassLoader.java b/modules/core/src/main/java/org/apache/ignite/internal/managers/deployment/GridDeploymentClassLoader.java index bb5458c..925c033 100644 --- a/modules/core/src/main/java/org/apache/ignite/internal/managers/deployment/GridDeploymentClassLoader.java +++ b/modules/core/src/main/java/org/apache/ignite/internal/managers/deployment/GridDeploymentClassLoader.java @@ -26,6 +26,7 @@ import java.util.Collection; import java.util.Collections; import java.util.HashMap; import java.util.LinkedList; +import java.util.List; import java.util.Map; import java.util.UUID; import java.util.concurrent.ConcurrentHashMap; @@ -42,7 +43,9 @@ import org.apache.ignite.internal.util.GridByteArrayList; import org.apache.ignite.internal.util.tostring.GridToStringExclude; import org.apache.ignite.internal.util.tostring.GridToStringInclude; import org.apache.ignite.internal.util.typedef.X; +import org.apache.ignite.internal.util.typedef.internal.LT; import org.apache.ignite.internal.util.typedef.internal.S; +import org.apache.ignite.internal.util.typedef.internal.SB; import org.apache.ignite.internal.util.typedef.internal.U; import org.apache.ignite.lang.IgniteUuid; import org.jetbrains.annotations.Nullable; @@ -124,6 +127,9 @@ class GridDeploymentClassLoader extends ClassLoader implements GridDeploymentInf /** */ private final Object mux = new Object(); + /** */ + private final String clsLdrHierarchy = classLoadersHierarchy(); + /** * Creates a new peer class loader. * <p> @@ -595,9 +601,11 @@ class GridDeploymentClassLoader extends ClassLoader implements GridDeploymentInf synchronized (mux) { // Skip requests for the previously missed classes. - if (missedRsrcs != null && missedRsrcs.contains(path)) - throw new ClassNotFoundException("Failed to peer load class [class=" + name + ", nodeClsLdrIds=" + - nodeLdrMap + ", parentClsLoader=" + getParent() + ']'); + if (missedRsrcs != null && missedRsrcs.contains(path)) { + throw new ClassNotFoundException("Failed to peer load class, previous request for the same class " + + "has failed [class=" + name + ", nodeClsLdrIds=" + + nodeLdrMap + ", clsLoadersHierarchy=" + clsLdrHierarchy + ']'); + } // If single-node mode, then node cannot change and we simply reuse list and map. // Otherwise, make copies that can be used outside synchronization. @@ -605,9 +613,7 @@ class GridDeploymentClassLoader extends ClassLoader implements GridDeploymentInf nodeLdrMapCp = singleNode ? nodeLdrMap : new HashMap<>(nodeLdrMap); } - IgniteCheckedException err = null; - - TimeoutException te = null; + List<IgniteException> classRequestExceptions = new ArrayList<>(); for (UUID nodeId : nodeListCp) { if (nodeId.equals(ctx.discovery().localNode().id())) @@ -626,80 +632,89 @@ class GridDeploymentClassLoader extends ClassLoader implements GridDeploymentInf } try { - GridDeploymentResponse res = null; - - try { - res = comm.sendResourceRequest(path, ldrId, node, endTime); - } - catch (TimeoutException e) { - te = e; - } - - if (res == null) { - String msg = "Failed to send class-loading request to node (is node alive?) [node=" + - node.id() + ", clsName=" + name + ", clsPath=" + path + ", clsLdrId=" + ldrId + - ", parentClsLdr=" + getParent() + ']'; - - if (!quiet) - U.warn(log, msg); - else if (log.isDebugEnabled()) - log.debug(msg); - - err = new IgniteCheckedException(msg); - - continue; - } + GridDeploymentResponse res = comm.sendResourceRequest(path, ldrId, node, endTime); if (res.success()) return res.byteSource(); + else { + // In case of shared resources/classes all nodes should have it. + String msg = "Failed to find class on remote node [class=" + name + ", nodeId=" + node.id() + + ", clsLdrId=" + ldrId + ", classLoadersHierarchy=" + clsLdrHierarchy + + ", reason=" + res.errorMessage() + ']'; - // In case of shared resources/classes all nodes should have it. - if (log.isDebugEnabled()) - log.debug("Failed to find class on remote node [class=" + name + ", nodeId=" + node.id() + - ", clsLdrId=" + ldrId + ", reason=" + res.errorMessage() + ']'); + LT.warn(log, msg); - synchronized (mux) { - if (missedRsrcs != null) - missedRsrcs.add(path); - } + classRequestExceptions.add(new IgniteException(msg)); + + synchronized (mux) { + if (missedRsrcs != null) + missedRsrcs.add(path); + } - throw new ClassNotFoundException("Failed to peer load class [class=" + name + ", nodeClsLdrs=" + - nodeLdrMapCp + ", parentClsLoader=" + getParent() + ", reason=" + res.errorMessage() + ']'); + break; + } } catch (IgniteCheckedException e) { // This thread should be interrupted again in communication if it // got interrupted. So we assume that thread can be interrupted // by processing cancellation request. if (Thread.currentThread().isInterrupted()) { + String msg = "Failed to find class probably due to task/job cancellation [name=" + name + + ", clsLdrId=" + ldrId + + ", nodeId=" + nodeId + + ", clsLoadersHierarchy=" + clsLdrHierarchy + ']'; + if (!quiet) - U.error(log, "Failed to find class probably due to task/job cancellation: " + name, e); + U.error(log, msg, e); else if (log.isDebugEnabled()) - log.debug("Failed to find class probably due to task/job cancellation [name=" + name + - ", err=" + e + ']'); + log.debug(msg); } else { + String msg = "Failed to send class-loading request to node (is node alive?) [" + + "node=" + node.id() + + ", clsName=" + name + + ", clsPath=" + path + + ", clsLdrId=" + ldrId + + ", clsLoadersHierarchy=" + clsLdrHierarchy + + ", err=" + e + ']'; + if (!quiet) - U.warn(log, "Failed to send class-loading request to node (is node alive?) [node=" + - node.id() + ", clsName=" + name + ", clsPath=" + path + ", clsLdrId=" + ldrId + - ", parentClsLdr=" + getParent() + ", err=" + e + ']'); + U.warn(log, msg, e); else if (log.isDebugEnabled()) - log.debug("Failed to send class-loading request to node (is node alive?) [node=" + - node.id() + ", clsName=" + name + ", clsPath=" + path + ", clsLdrId=" + ldrId + - ", parentClsLdr=" + getParent() + ", err=" + e + ']'); + log.debug(msg); - err = e; + classRequestExceptions.add(new IgniteException(msg, e)); } } + catch (TimeoutException e) { + classRequestExceptions.add(new IgniteException("Failed to send class-loading request to node (is node alive?) " + + "[node=" + node.id() + ", clsName=" + name + ", clsPath=" + path + ", clsLdrId=" + ldrId + + ", clsLoadersHierarchy=" + clsLdrHierarchy + ']', e)); + } } - if (te != null) { - err.addSuppressed(te); + if (!classRequestExceptions.isEmpty()) { + IgniteException exception = classRequestExceptions.remove(0); - throw new IgniteException(err); + for (Exception e : classRequestExceptions) + exception.addSuppressed(e); + + LT.warn(log, exception.getMessage(), exception); + + throw exception; } + else { + ClassNotFoundException cnfe = new ClassNotFoundException("Failed to peer load class [" + + "class=" + name + + ", nodeClsLdrs=" + nodeLdrMapCp + + ", clsLoadersHierarchy=" + clsLdrHierarchy + + ']' + ); + + LT.warn(log, cnfe.getMessage(), cnfe); - throw new ClassNotFoundException("Failed to peer load class [class=" + name + ", nodeClsLdrs=" + - nodeLdrMapCp + ", parentClsLoader=" + getParent() + ']', err); + throw cnfe; + } } /** {@inheritDoc} */ @@ -792,12 +807,11 @@ class GridDeploymentClassLoader extends ClassLoader implements GridDeploymentInf // Request is sent with timeout that is why we can use synchronization here. GridDeploymentResponse res = comm.sendResourceRequest(name, ldrId, node, endTime); - if (res == null) { - U.warn(log, "Failed to get resource from node (is node alive?) [nodeId=" + - node.id() + ", clsLdrId=" + ldrId + ", resName=" + - name + ", parentClsLdr=" + getParent() + ']'); + if (res.success()) { + return new ByteArrayInputStream(res.byteSource().internalArray(), 0, + res.byteSource().size()); } - else if (!res.success()) { + else { synchronized (mux) { // Cache unsuccessfully loaded resource. if (missedRsrcs != null) @@ -807,45 +821,44 @@ class GridDeploymentClassLoader extends ClassLoader implements GridDeploymentInf // Some frameworks like Spring often ask for the resources // just in case - none will happen if there are no such // resources. So we print out INFO level message. - if (!quiet) { - if (log.isInfoEnabled()) - log.info("Failed to get resource from node [nodeId=" + - node.id() + ", clsLdrId=" + ldrId + ", resName=" + - name + ", parentClsLdr=" + getParent() + ", msg=" + res.errorMessage() + ']'); - } - else if (log.isDebugEnabled()) - log.debug("Failed to get resource from node [nodeId=" + - node.id() + ", clsLdrId=" + ldrId + ", resName=" + - name + ", parentClsLdr=" + getParent() + ", msg=" + res.errorMessage() + ']'); + String msg = "Failed to get resource from node [" + + "nodeId=" + node.id() + + ", clsLdrId=" + ldrId + + ", resName=" + name + + ", classLoadersHierarchy=" + classLoadersHierarchy() + + ", msg=" + res.errorMessage() + ']'; + + LT.info(log, msg); // Do not ask other nodes in case of shared mode all of them should have the resource. return null; } - else { - return new ByteArrayInputStream(res.byteSource().internalArray(), 0, - res.byteSource().size()); - } } - catch (IgniteCheckedException e) { + catch (IgniteCheckedException | TimeoutException e) { // This thread should be interrupted again in communication if it // got interrupted. So we assume that thread can be interrupted // by processing cancellation request. if (Thread.currentThread().isInterrupted()) { - if (!quiet) - U.error(log, "Failed to get resource probably due to task/job cancellation: " + name, e); - else if (log.isDebugEnabled()) - log.debug("Failed to get resource probably due to task/job cancellation: " + name); + String msg = "Failed to get resource probably due to task/job cancellation [name=" + name + + ", clsLdrId=" + ldrId + + ", nodeId=" + nodeId + + ", clsLoadersHierarchy=" + classLoadersHierarchy() + ']'; + + LT.error(log, e, msg); } else { - if (!quiet) - U.warn(log, "Failed to get resource from node (is node alive?) [nodeId=" + - node.id() + ", clsLdrId=" + ldrId + ", resName=" + - name + ", parentClsLdr=" + getParent() + ", err=" + e + ']'); - else if (log.isDebugEnabled()) - log.debug("Failed to get resource from node (is node alive?) [nodeId=" + - node.id() + ", clsLdrId=" + ldrId + ", resName=" + - name + ", parentClsLdr=" + getParent() + ", err=" + e + ']'); + String msg = "Failed to get resource from node (is node alive?) [" + + "node=" + node.id() + + ", resName=" + name + + ", clsLdrId=" + ldrId + + ", clsLoadersHierarchy=" + classLoadersHierarchy() + + ", err=" + e + ']'; + + LT.warn(log, msg, e); } + + if (e instanceof TimeoutException) + throw (TimeoutException) e; } } @@ -858,4 +871,27 @@ class GridDeploymentClassLoader extends ClassLoader implements GridDeploymentInf return S.toString(GridDeploymentClassLoader.class, this); } } + + /** + * @return Hierarchy of all parents of this class loader. + */ + private String classLoadersHierarchy() { + SB sb = new SB(); + + sb.a(getClass().getName()); + + ClassLoader ldr = this; + + int iterations = 100; + + while (ldr.getParent() != null && iterations > 0) { + sb.a("->").a(ldr.getParent().getClass().getName()); + + ldr = ldr.getParent(); + + iterations--; + } + + return sb.toString(); + } } diff --git a/modules/core/src/main/java/org/apache/ignite/internal/managers/deployment/GridDeploymentCommunication.java b/modules/core/src/main/java/org/apache/ignite/internal/managers/deployment/GridDeploymentCommunication.java index 3cd5861..44a3661 100644 --- a/modules/core/src/main/java/org/apache/ignite/internal/managers/deployment/GridDeploymentCommunication.java +++ b/modules/core/src/main/java/org/apache/ignite/internal/managers/deployment/GridDeploymentCommunication.java @@ -37,6 +37,7 @@ import org.apache.ignite.internal.util.GridBusyLock; import org.apache.ignite.internal.util.GridByteArrayList; import org.apache.ignite.internal.util.lang.GridTuple; import org.apache.ignite.internal.util.tostring.GridToStringExclude; +import org.apache.ignite.internal.util.typedef.internal.SB; import org.apache.ignite.internal.util.typedef.internal.U; import org.apache.ignite.lang.IgniteNotPeerDeployable; import org.apache.ignite.lang.IgniteUuid; @@ -183,14 +184,15 @@ class GridDeploymentCommunication { */ private void processResourceRequest(UUID nodeId, GridDeploymentRequest req) { if (log.isDebugEnabled()) - log.debug("Received peer class/resource loading request [node=" + nodeId + ", req=" + req + ']'); + log.debug("Received peer class/resource loading request [originatingNodeId=" + nodeId + ", req=" + req + ']'); if (req.responseTopic() == null) { try { req.responseTopic(U.unmarshal(marsh, req.responseTopicBytes(), U.resolveClassLoader(ctx.config()))); } catch (IgniteCheckedException e) { - U.error(log, "Failed to process deployment request (will ignore): " + req, e); + U.error(log, "Failed to process deployment request (will ignore) [" + + "originatingNodeId=" + nodeId + ", req=" + req + ']', e); return; } @@ -217,7 +219,7 @@ class GridDeploymentCommunication { Class<?> cls = Class.forName(clsName, true, ldr); if (U.getAnnotation(cls, IgniteNotPeerDeployable.class) != null) { - String errMsg = "Attempt to peer deploy class that has @GridNotPeerDeployable " + + String errMsg = "Attempt to peer deploy class that has @IgniteNotPeerDeployable " + "annotation: " + clsName; U.error(log, errMsg); @@ -231,7 +233,9 @@ class GridDeploymentCommunication { } } catch (LinkageError | ClassNotFoundException e) { - U.warn(log, "Failed to resolve class: " + clsName, e); + U.warn(log, "Failed to resolve class [originatingNodeId=" + nodeId + ", class=" + clsName + + ", req=" + req + ']', e + ); // Defined errors can be safely ignored here, because of resource which is able to be not a class name. // Unsuccessful response will be sent below if the resource failed to be loaded. } @@ -240,7 +244,7 @@ class GridDeploymentCommunication { InputStream in = ldr.getResourceAsStream(req.resourceName()); if (in == null) { - String errMsg = "Requested resource not found (ignoring locally): " + req.resourceName(); + String errMsg = "Requested resource not found (ignoring locally) " + resourceRequestDetails(nodeId, req); // Java requests the same class with BeanInfo suffix during // introspection automatically. Usually nobody uses this kind @@ -265,7 +269,7 @@ class GridDeploymentCommunication { res.byteSource(bytes); } catch (IOException e) { - String errMsg = "Failed to read resource due to IO failure: " + req.resourceName(); + String errMsg = "Failed to read resource due to IO failure " + resourceRequestDetails(nodeId, req); U.error(log, errMsg, e); @@ -278,7 +282,8 @@ class GridDeploymentCommunication { } } else { - String errMsg = "Failed to find local deployment for peer request: " + req; + String errMsg = "Failed to find local deployment for peer request [" + + "originatingNodeId=" + nodeId + ", req=" + req + ']'; U.warn(log, errMsg); @@ -289,6 +294,16 @@ class GridDeploymentCommunication { sendResponse(nodeId, req.responseTopic(), res); } + /** */ + private String resourceRequestDetails(UUID nodeId, GridDeploymentRequest req) { + return new SB() + .a("[originatingNodeId=").a(nodeId) + .a(", resourceName=").a(req.resourceName()) + .a(", classLoaderId=").a(req.classLoaderId()) + .a(']') + .toString(); + } + /** * @param nodeId Destination node ID. * @param topic Response topic. @@ -346,14 +361,14 @@ class GridDeploymentCommunication { * Sends request to the remote node and wait for response. If there is * no response until threshold time, method returns null. * - * * @param rsrcName Resource name. * @param clsLdrId Class loader ID. * @param dstNode Remote node request should be sent to. * @param threshold Time in milliseconds when request is decided to * be obsolete. - * @return Either response value or {@code null} if timeout occurred. + * @return Response value. * @throws IgniteCheckedException Thrown if there is no connection with remote node. + * @throws TimeoutException If request timed out. */ GridDeploymentResponse sendResourceRequest(final String rsrcName, IgniteUuid clsLdrId, final ClusterNode dstNode, long threshold) throws IgniteCheckedException, TimeoutException { @@ -364,19 +379,9 @@ class GridDeploymentCommunication { Collection<UUID> nodeIds = activeReqNodeIds.get(); if (nodeIds != null && nodeIds.contains(dstNode.id())) { - if (log.isDebugEnabled()) - log.debug("Node attempts to load resource from one of the requesters " + - "[rsrcName=" + rsrcName + ", dstNodeId=" + dstNode.id() + - ", requesters=" + nodeIds + ']'); - - GridDeploymentResponse fake = new GridDeploymentResponse(); - - fake.success(false); - fake.errorMessage("Node attempts to load resource from one of the requesters " + + throw new IgniteCheckedException("Node attempts to load resource from one of the requesters " + "[rsrcName=" + rsrcName + ", dstNodeId=" + dstNode.id() + - ", requesters=" + nodeIds + ']'); - - return fake; + ", requesters=" + nodeIds + ']'); } Object resTopic = TOPIC_CLASSLOAD.topic(IgniteUuid.fromUuid(ctx.localNodeId())); @@ -390,57 +395,9 @@ class GridDeploymentCommunication { final GridTuple<GridDeploymentResponse> res = new GridTuple<>(); - GridLocalEventListener discoLsnr = new GridLocalEventListener() { - @Override public void onEvent(Event evt) { - assert evt instanceof DiscoveryEvent; - - assert evt.type() == EVT_NODE_LEFT || evt.type() == EVT_NODE_FAILED; - - DiscoveryEvent discoEvt = (DiscoveryEvent)evt; - - UUID nodeId = discoEvt.eventNode().id(); + GridLocalEventListener discoLsnr = resourceDiscoListener(res, dstNode, rsrcName, qryMux); - if (!nodeId.equals(dstNode.id())) - // Not a destination node. - return; - - GridDeploymentResponse fake = new GridDeploymentResponse(); - - String errMsg = "Originating node left grid (resource will not be peer loaded) " + - "[nodeId=" + dstNode.id() + ", rsrc=" + rsrcName + ']'; - - U.warn(log, errMsg); - - fake.success(false); - fake.errorMessage(errMsg); - - // We put fake result here to interrupt waiting peer-to-peer thread - // because originating node has left grid. - synchronized (qryMux) { - res.set(fake); - - qryMux.notifyAll(); - } - } - }; - - GridMessageListener resLsnr = new GridMessageListener() { - @Override public void onMessage(UUID nodeId, Object msg, byte plc) { - assert nodeId != null; - assert msg != null; - - synchronized (qryMux) { - if (!(msg instanceof GridDeploymentResponse)) { - U.error(log, "Received unknown peer class loading response [node=" + nodeId + ", msg=" + - msg + ']'); - } - else - res.set((GridDeploymentResponse)msg); - - qryMux.notifyAll(); - } - } - }; + GridMessageListener resLsnr = resourceMessageListener(res, qryMux); try { ctx.io().addMessageListener(resTopic, resLsnr); @@ -491,12 +448,7 @@ class GridDeploymentCommunication { } } - if (res.get() == null) { - U.warn(log, "Failed to receive peer response from node within duration [node=" + dstNode.id() + - ", duration=" + (U.currentTimeMillis() - start) + ']'); - } - else if (log.isDebugEnabled()) - log.debug("Received peer loading response [node=" + dstNode.id() + ", res=" + res.get() + ']'); + assert res.get() != null; return res.get(); } @@ -506,4 +458,87 @@ class GridDeploymentCommunication { ctx.io().removeMessageListener(resTopic, resLsnr); } } + + /** + * @param res Result holder. + * @param dstNode Destination node. + * @param rsrcName Resource name. + * @param qryMux Mutex. + * @return Listener for discovery events {@code EVT_NODE_LEFT} and {@code EVT_NODE_FAILED} for class loading + * requests. + */ + public GridLocalEventListener resourceDiscoListener( + GridTuple<GridDeploymentResponse> res, + ClusterNode dstNode, + String rsrcName, + Object qryMux + ) { + return new GridLocalEventListener() { + @Override public void onEvent(Event evt) { + assert evt instanceof DiscoveryEvent; + + assert evt.type() == EVT_NODE_LEFT || evt.type() == EVT_NODE_FAILED; + + DiscoveryEvent discoEvt = (DiscoveryEvent)evt; + + UUID nodeId = discoEvt.eventNode().id(); + + if (!nodeId.equals(dstNode.id())) + // Not a destination node. + return; + + GridDeploymentResponse fake = new GridDeploymentResponse(); + + String errMsg = "Originating node left grid (resource will not be peer loaded) " + + "[nodeId=" + dstNode.id() + ", rsrc=" + rsrcName + ']'; + + U.warn(log, errMsg); + + fake.success(false); + fake.errorMessage(errMsg); + + // We put fake result here to interrupt waiting peer-to-peer thread + // because originating node has left grid. + synchronized (qryMux) { + res.set(fake); + + qryMux.notifyAll(); + } + } + }; + } + + /** + * @param res Result holder. + * @param qryMux Mutex. + * @return Listener for response message for class loading requests. + */ + public GridMessageListener resourceMessageListener(GridTuple<GridDeploymentResponse> res, Object qryMux) { + return new GridMessageListener() { + @Override public void onMessage(UUID nodeId, Object msg, byte plc) { + assert nodeId != null; + assert msg != null; + + synchronized (qryMux) { + if (!(msg instanceof GridDeploymentResponse)) { + GridDeploymentResponse fake = new GridDeploymentResponse(); + + String errMsg = "Received unknown peer class loading response [node=" + nodeId + + ", msg=" + msg + ']'; + + U.error(log, errMsg); + + fake.success(false); + fake.errorMessage(errMsg); + + res.set(fake); + } + else + res.set((GridDeploymentResponse)msg); + + qryMux.notifyAll(); + } + } + }; + } } diff --git a/modules/core/src/main/java/org/apache/ignite/internal/util/GridLogThrottle.java b/modules/core/src/main/java/org/apache/ignite/internal/util/GridLogThrottle.java index ac9c335..27fe9da 100644 --- a/modules/core/src/main/java/org/apache/ignite/internal/util/GridLogThrottle.java +++ b/modules/core/src/main/java/org/apache/ignite/internal/util/GridLogThrottle.java @@ -150,6 +150,19 @@ public class GridLogThrottle { } /** + * Logs warning if needed. + * + * @param log Logger. + * @param msg Message. + * @param e Error.. + */ + public static void warn(@Nullable IgniteLogger log, String msg, Throwable e) { + assert !F.isEmpty(msg); + + log(log, e, msg, LogLevel.WARN, false, false); + } + + /** * Logs info if needed. * * @param log Logger. diff --git a/modules/core/src/test/java/org/apache/ignite/internal/TestRecordingCommunicationSpi.java b/modules/core/src/test/java/org/apache/ignite/internal/TestRecordingCommunicationSpi.java index 8348147..95a8266 100644 --- a/modules/core/src/test/java/org/apache/ignite/internal/TestRecordingCommunicationSpi.java +++ b/modules/core/src/test/java/org/apache/ignite/internal/TestRecordingCommunicationSpi.java @@ -284,7 +284,7 @@ public class TestRecordingCommunicationSpi extends TcpCommunicationSpi { /** * @param cls Message class. - * @param nodeName Node name. + * @param nodeName Name of the node where message is sent to. */ public void blockMessages(Class<?> cls, String nodeName) { synchronized (this) { diff --git a/modules/core/src/test/java/org/apache/ignite/internal/managers/deployment/DeploymentRequestOfUnknownClassProcessingTest.java b/modules/core/src/test/java/org/apache/ignite/internal/managers/deployment/DeploymentRequestOfUnknownClassProcessingTest.java index 1c6027f..7997e88 100644 --- a/modules/core/src/test/java/org/apache/ignite/internal/managers/deployment/DeploymentRequestOfUnknownClassProcessingTest.java +++ b/modules/core/src/test/java/org/apache/ignite/internal/managers/deployment/DeploymentRequestOfUnknownClassProcessingTest.java @@ -97,7 +97,7 @@ public class DeploymentRequestOfUnknownClassProcessingTest extends GridCommonAbs final GridFutureAdapter<Void> testResultFut = new GridFutureAdapter<>(); final LogListener remNodeLogLsnr = LogListener - .matches(s -> s.startsWith("Failed to resolve class: " + UNKNOWN_CLASS_NAME)).build(); + .matches(s -> s.matches("Failed to resolve class.*?" + UNKNOWN_CLASS_NAME + ".*")).build(); remNodeLog.registerListener(remNodeLogLsnr); @@ -115,7 +115,7 @@ public class DeploymentRequestOfUnknownClassProcessingTest extends GridCommonAbs assertNotNull("Response should contain an error message.", errMsg); assertTrue("Response contains unexpected error message, errorMessage=" + errMsg, - errMsg.startsWith("Requested resource not found (ignoring locally): " + UNKNOWN_CLASS_NAME)); + errMsg.matches("Requested resource not found \\(ignoring locally\\).*?" + UNKNOWN_CLASS_NAME + ".*")); testResultFut.onDone(); } diff --git a/modules/core/src/test/java/org/apache/ignite/p2p/ClassLoadingProblemExtendedLoggingTest.java b/modules/core/src/test/java/org/apache/ignite/p2p/ClassLoadingProblemExtendedLoggingTest.java new file mode 100644 index 0000000..0aae23e --- /dev/null +++ b/modules/core/src/test/java/org/apache/ignite/p2p/ClassLoadingProblemExtendedLoggingTest.java @@ -0,0 +1,178 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache License, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package org.apache.ignite.p2p; + +import java.util.List; +import java.util.concurrent.TimeoutException; +import java.util.concurrent.atomic.AtomicInteger; +import org.apache.ignite.configuration.IgniteConfiguration; +import org.apache.ignite.internal.IgniteEx; +import org.apache.ignite.internal.TestRecordingCommunicationSpi; +import org.apache.ignite.internal.managers.deployment.GridDeploymentRequest; +import org.apache.ignite.internal.managers.deployment.GridDeploymentResponse; +import org.apache.ignite.internal.util.typedef.internal.LT; +import org.apache.ignite.testframework.ListeningTestLogger; +import org.apache.ignite.testframework.LogListener; +import org.apache.ignite.testframework.junits.common.GridCommonAbstractTest; +import org.junit.Test; +import org.junit.runner.RunWith; +import org.junit.runners.Parameterized; + +import static com.google.common.primitives.Ints.asList; +import static org.apache.ignite.configuration.DeploymentMode.SHARED; +import static org.apache.ignite.internal.TestRecordingCommunicationSpi.spi; +import static org.apache.ignite.testframework.GridTestUtils.setFieldValue; + +/** + * Tests of extended logging of class loading problems. + */ +@RunWith(Parameterized.class) +public class ClassLoadingProblemExtendedLoggingTest extends GridCommonAbstractTest { + /** */ + private ListeningTestLogger listeningLog = new ListeningTestLogger(log); + + /** */ + private IgniteEx ignite; + + /** */ + private IgniteEx client; + + /** */ + @Parameterized.Parameter(0) + public Integer allowSuccessfulClassRequestsCnt; + + @Parameterized.Parameters(name = "{0}") + public static List<Integer> allowSuccessfulClassRequestsCntList() { + return asList(0, 1); + } + + /** {@inheritDoc} */ + @Override protected IgniteConfiguration getConfiguration(String igniteInstanceName) throws Exception { + return super.getConfiguration(igniteInstanceName) + .setPeerClassLoadingEnabled(true) + .setDeploymentMode(SHARED) + .setCommunicationSpi(new TestRecordingCommunicationSpi()) + .setGridLogger(listeningLog) + .setNetworkTimeout(1000); + } + + /** {@inheritDoc} */ + @Override protected void beforeTest() throws Exception { + super.beforeTest(); + + stopAllGrids(); + + LT.clear(); + + listeningLog.clearListeners(); + + ignite = startGrid(0); + + client = startClientGrid(1); + } + + /** {@inheritDoc} */ + @Override protected void afterTest() throws Exception { + stopAllGrids(); + + LT.clear(); + + super.afterTest(); + } + + /** Tests logging when executing job with communication problems. */ + @Test + public void testTimeout() throws ClassNotFoundException { + LogListener lsnr1 = LogListener + .matches(msg -> msg + .replace("\n", "") + .matches(".*?Failed to get resource from node \\(is node alive\\?\\).*?" + + TimeoutException.class.getName() + ".*") + ) + .build(); + + LogListener lsnr2 = LogListener + .matches("Failed to send class-loading request to node") + .build(); + + listeningLog.registerListener(lsnr1); + listeningLog.registerListener(lsnr2); + + TestRecordingCommunicationSpi clientSpi = spi(client); + + AtomicInteger reqCntr = new AtomicInteger(0); + + spi(ignite).closure((node, msg) -> { + if (msg instanceof GridDeploymentRequest && allowSuccessfulClassRequestsCnt - reqCntr.get() <= 0) + clientSpi.blockMessages(GridDeploymentResponse.class, ignite.name()); + + reqCntr.incrementAndGet(); + }); + + Class cls = getExternalClassLoader() + .loadClass("org.apache.ignite.tests.p2p.P2PTestTaskExternalPath1"); + + try { + client.compute().execute(cls, ignite.cluster().localNode().id()); + } + catch (Exception ignored) { + /* No-op. */ + } + + doSleep(1500); + + assertTrue(lsnr1.check() || lsnr2.check()); + + clientSpi.stopBlock(); + } + + /** Tests logging when executing job and class is not found on initiator. */ + @Test + public void testCNFE() throws Exception { + LogListener srvLsnr1 = LogListener.matches("Failed to get resource from node").build(); + LogListener srvLsnr2 = LogListener.matches("Failed to find class on remote node").build(); + LogListener clientLsnr = LogListener.matches("Failed to resolve class").build(); + + listeningLog.registerListener(srvLsnr1); + listeningLog.registerListener(srvLsnr2); + listeningLog.registerListener(clientLsnr); + + AtomicInteger reqCntr = new AtomicInteger(0); + + spi(ignite).closure((node, msg) -> { + if (msg instanceof GridDeploymentRequest && allowSuccessfulClassRequestsCnt - reqCntr.get() <= 0) + setFieldValue(msg, "rsrcName", "asdf"); + + reqCntr.incrementAndGet(); + }); + + Class cls = getExternalClassLoader() + .loadClass("org.apache.ignite.tests.p2p.P2PTestTaskExternalPath1"); + + try { + client.compute().execute(cls, ignite.cluster().localNode().id()); + } + catch (Exception ignored) { + /* No-op. */ + } + + assertTrue(srvLsnr1.check() || srvLsnr2.check()); + assertTrue(clientLsnr.check()); + + spi(ignite).closure(null); + } +} diff --git a/modules/extdata/p2p/src/main/java/org/apache/ignite/tests/p2p/P2PTestPredicate.java b/modules/extdata/p2p/src/main/java/org/apache/ignite/tests/p2p/P2PTestPredicate.java index 1bd6ea8..f650337 100644 --- a/modules/extdata/p2p/src/main/java/org/apache/ignite/tests/p2p/P2PTestPredicate.java +++ b/modules/extdata/p2p/src/main/java/org/apache/ignite/tests/p2p/P2PTestPredicate.java @@ -25,7 +25,6 @@ import org.apache.ignite.lang.IgniteBiPredicate; /** * Test predicate for scan queries in p2p deployment tests. */ -@SuppressWarnings("unused") public class P2PTestPredicate extends GridCacheIdMessage implements GridCacheDeployable, IgniteBiPredicate, Serializable { /** */ private static final long serialVersionUID = 0L; diff --git a/modules/urideploy/src/test/java/org/apache/ignite/testsuites/IgniteUriDeploymentTestSuite.java b/modules/urideploy/src/test/java/org/apache/ignite/testsuites/IgniteUriDeploymentTestSuite.java index 7f975ce..a5b49fa 100644 --- a/modules/urideploy/src/test/java/org/apache/ignite/testsuites/IgniteUriDeploymentTestSuite.java +++ b/modules/urideploy/src/test/java/org/apache/ignite/testsuites/IgniteUriDeploymentTestSuite.java @@ -20,6 +20,7 @@ package org.apache.ignite.testsuites; import org.apache.ignite.internal.GridTaskUriDeploymentDeadlockSelfTest; import org.apache.ignite.internal.UriDeploymentAbsentProcessorClassTest; import org.apache.ignite.p2p.ClassLoadingProblemExceptionTest; +import org.apache.ignite.p2p.ClassLoadingProblemExtendedLoggingTest; import org.apache.ignite.p2p.GridP2PDisabledSelfTest; import org.apache.ignite.spi.deployment.uri.GridUriDeploymentClassLoaderMultiThreadedSelfTest; import org.apache.ignite.spi.deployment.uri.GridUriDeploymentClassLoaderSelfTest; @@ -63,6 +64,7 @@ import org.junit.runners.Suite; GridTaskUriDeploymentDeadlockSelfTest.class, GridP2PDisabledSelfTest.class, ClassLoadingProblemExceptionTest.class, + ClassLoadingProblemExtendedLoggingTest.class, UriDeploymentAbsentProcessorClassTest.class }) public class IgniteUriDeploymentTestSuite {