[
https://issues.apache.org/jira/browse/IGNITE-1606?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16953832#comment-16953832
]
Dmitriy Sorokin edited comment on IGNITE-1606 at 10/17/19 3:11 PM:
-------------------------------------------------------------------
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?
was (Author: cyberdemon):
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)
