You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@ignite.apache.org by "Dmitriy Sorokin (Jira)" <ji...@apache.org> on 2019/10/17 15:09:00 UTC

[jira] [Commented] (IGNITE-1606) NPE during node stop due to nullified logger in TcpCommunicationSpi

    [ https://issues.apache.org/jira/browse/IGNITE-1606?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16953832#comment-16953832 ] 

Dmitriy Sorokin commented on IGNITE-1606:
-----------------------------------------

The issue with access to nullified log field is present at the current master branch (2.8-SNAPSHOT) not only in TcpCommunicationSpi but also in TcpDiscoveryMulticastIpFinder, see stacktraces below:
{code:java}
[2019-09-24 15:31:19,018][ERROR][sys-stripe-0-#325%worker-8%][root] Critical system error detected. Will be handled accordingly to configured handler [hnd=StopNodeOrHaltFailureHandler [tryStop=false, timeout=0, super=AbstractFailureHandler [ignoredFailureTypes=UnmodifiableSet [SYSTEM_WORKER_BLOCKED, SYSTEM_CRITICAL_OPERATION_TIMEOUT]]], failureCtx=FailureContext [type=SYSTEM_WORKER_TERMINATION, err=java.lang.NullPointerException]][2019-09-24 15:31:19,018][ERROR][sys-stripe-0-#325%worker-8%][root] Critical system error detected. Will be handled accordingly to configured handler [hnd=StopNodeOrHaltFailureHandler [tryStop=false, timeout=0, super=AbstractFailureHandler [ignoredFailureTypes=UnmodifiableSet [SYSTEM_WORKER_BLOCKED, SYSTEM_CRITICAL_OPERATION_TIMEOUT]]], failureCtx=FailureContext [type=SYSTEM_WORKER_TERMINATION, err=java.lang.NullPointerException]]java.lang.NullPointerException at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi.sendMessage0(TcpCommunicationSpi.java:2821) at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi.sendMessage(TcpCommunicationSpi.java:2805) at org.apache.ignite.internal.managers.communication.GridIoManager.send(GridIoManager.java:2031) at org.apache.ignite.internal.managers.communication.GridIoManager.sendToGridTopic(GridIoManager.java:2128) at org.apache.ignite.internal.processors.cache.GridCacheIoManager.send(GridCacheIoManager.java:1257) at org.apache.ignite.internal.processors.cache.GridCacheIoManager.send(GridCacheIoManager.java:1296) at org.apache.ignite.internal.processors.cache.distributed.dht.atomic.GridDhtAtomicCache.sendDeferredUpdateResponse(GridDhtAtomicCache.java:3619) at org.apache.ignite.internal.processors.cache.distributed.dht.atomic.GridDhtAtomicCache.access$3300(GridDhtAtomicCache.java:142) at org.apache.ignite.internal.processors.cache.distributed.dht.atomic.GridDhtAtomicCache$DeferredUpdateTimeout.run(GridDhtAtomicCache.java:3865) at org.apache.ignite.internal.util.StripedExecutor$Stripe.body(StripedExecutor.java:550) at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120) at java.lang.Thread.run(Thread.java:748)
{code}
 
{code:java}
[2019-09-24 15:31:11,411][ERROR][tcp-client-disco-reconnector-#64%worker-4%][TcpDiscoverySpi] Runtime error caught during grid runnable execution: IgniteSpiThread [name=tcp-client-disco-reconnector-#64%worker-4%][2019-09-24 15:31:11,411][ERROR][tcp-client-disco-reconnector-#64%worker-4%][TcpDiscoverySpi] Runtime error caught during grid runnable execution: IgniteSpiThread [name=tcp-client-disco-reconnector-#64%worker-4%]java.lang.NullPointerException at org.apache.ignite.spi.discovery.tcp.ipfinder.multicast.TcpDiscoveryMulticastIpFinder.requestAddresses(TcpDiscoveryMulticastIpFinder.java:637) at org.apache.ignite.spi.discovery.tcp.ipfinder.multicast.TcpDiscoveryMulticastIpFinder.getRegisteredAddresses(TcpDiscoveryMulticastIpFinder.java:392) at org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi.registeredAddresses(TcpDiscoverySpi.java:1944) at org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi.resolvedAddresses(TcpDiscoverySpi.java:1892) at org.apache.ignite.spi.discovery.tcp.ClientImpl.joinTopology(ClientImpl.java:562) at org.apache.ignite.spi.discovery.tcp.ClientImpl.access$1100(ClientImpl.java:141) at org.apache.ignite.spi.discovery.tcp.ClientImpl$Reconnector.body(ClientImpl.java:1523)
{code}
 

 

I see two different solutions:

1) Replace constructions
{code:java}
if (log.isDebugEnabled())
    log.debug(...);{code}
and
{code:java}
if (log.isTraceEnabled())
    log.trace(...);{code}
by wrappers similar to U.error(...) and U.warn(...), where log reference will be checked for null before access.

 

2) Prevent nullifying of log references annotated by IgniteLogger at GridResourceProcessor.cleanup() method.

First solution seems more simple to me rather than second one, so I propose use that for resolving this issue.

Thoughts?

 

 

 

> NPE during node stop due to nullified logger in TcpCommunicationSpi
> -------------------------------------------------------------------
>
>                 Key: IGNITE-1606
>                 URL: https://issues.apache.org/jira/browse/IGNITE-1606
>             Project: Ignite
>          Issue Type: Bug
>          Components: general
>            Reporter: Valentin Kulichenko
>            Assignee: Dmitriy Sorokin
>            Priority: Major
>
> Probably we should check other components as well. Not sure why we need to nullify logger.
> {noformat}
> Exception in thread "ignite-#101%sys-t1-1%" java.lang.NullPointerException
> at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi.sendMessage0(TcpCommunicationSpi.java:1896)
> at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi.sendMessage(TcpCommunicationSpi.java:1880)
> at org.apache.ignite.internal.managers.communication.GridIoManager.send(GridIoManager.java:1066)
> at org.apache.ignite.internal.managers.communication.GridIoManager.send(GridIoManager.java:1214)
> at org.apache.ignite.internal.processors.continuous.GridContinuousProcessor.sendWithRetries(GridContinuousProcessor.java:1071)
> at org.apache.ignite.internal.processors.continuous.GridContinuousProcessor.sendWithRetries(GridContinuousProcessor.java:1034)
> at org.apache.ignite.internal.processors.continuous.GridContinuousProcessor.sendWithRetries(GridContinuousProcessor.java:1017)
> at org.apache.ignite.internal.processors.continuous.GridContinuousProcessor.processNotification(GridContinuousProcessor.java:851)
> at org.apache.ignite.internal.processors.continuous.GridContinuousProcessor.access$1500(GridContinuousProcessor.java:85)
> at org.apache.ignite.internal.processors.continuous.GridContinuousProcessor$8.onMessage(GridContinuousProcessor.java:556)
> at org.apache.ignite.internal.managers.communication.GridIoManager$GridCommunicationMessageSet.unwind(GridIoManager.java:2302)
> at org.apache.ignite.internal.managers.communication.GridIoManager.unwindMessageSet(GridIoManager.java:992)
> at org.apache.ignite.internal.managers.communication.GridIoManager.access$1700(GridIoManager.java:106)
> at org.apache.ignite.internal.managers.communication.GridIoManager$6.run(GridIoManager.java:961)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> {noformat}



--
This message was sent by Atlassian Jira
(v8.3.4#803005)