Ignite 2.81. - NULL pointer exception

classic Classic list List threaded Threaded
5 messages Options
Mahesh Renduchintala Mahesh Renduchintala
Reply | Threaded
Open this post in threaded view
|

Ignite 2.81. - NULL pointer exception

Hi, 

we have a null pointer exception in one of our servers.  No major activity was happening when the server crashed

Please check the logs and see if there is any workaround we can use.
We are in a production environment. 

regards
mahesh


281_nullpointerexception.log (17K) Download Attachment
ilya.kasnacheev ilya.kasnacheev
Reply | Threaded
Open this post in threaded view
|

Re: Ignite 2.81. - NULL pointer exception

Hello!

This seems to be an assertion failure that we did not see before. Please tell us if you see recurrence and especially if you can link it to some activity/

Regards,
--
Ilya Kasnacheev


ср, 5 авг. 2020 г. в 10:18, Mahesh Renduchintala <[hidden email]>:
Hi, 

we have a null pointer exception in one of our servers.  No major activity was happening when the server crashed

Please check the logs and see if there is any workaround we can use.
We are in a production environment. 

regards
mahesh

Mahesh Renduchintala Mahesh Renduchintala
Reply | Threaded
Open this post in threaded view
|

Re: Ignite 2.81. - NULL pointer exception

In reply to this post by Mahesh Renduchintala
We received this null pointer exception again


05:57:14,810][INFO][exchange-worker-#81][time] Finished exchange init [topVer=AffinityTopologyVersion [topVer=1139, minorTopVer=0], crd=true]
[05:57:15,553][INFO][exchange-worker-#81][GridCachePartitionExchangeManager] Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion [topVer=1139, minorTopVer=0], force=false, evt=NODE_FAILED, node=002bbc15-ae2f-4afc-b8a9-0c90c9aa25d4]
[05:57:15,920][INFO][grid-timeout-worker-#43][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=457c7279, uptime=1 day, 11:55:12.022]
    ^-- H/N/C [hosts=14, nodes=15, CPUs=49]
    ^-- CPU [cur=7.9%, avg=2.39%, GC=0.37%]
    ^-- PageMemory [pages=10033374]
    ^-- Heap [used=18402MB, free=62.56%, comm=49152MB]
    ^-- Off-heap [used=39652MB, free=39.77%, comm=65736MB]
    ^--   sysMemPlc region [used=0MB, free=99.98%, comm=100MB]
    ^--   default region [used=39651MB, free=39.5%, comm=65536MB]
    ^--   metastoreMemPlc region [used=1MB, free=98.96%, comm=0MB]
    ^--   TxLog region [used=0MB, free=100%, comm=100MB]
    ^-- Ignite persistence [used=39192MB]
    ^--   sysMemPlc region [used=0MB]
    ^--   default region [used=39191MB]
    ^--   metastoreMemPlc region [used=1MB]
    ^--   TxLog region [used=0MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=2, qSize=0]
    ^-- System thread pool [active=0, idle=32, qSize=0]
[05:57:16,153][INFO][exchange-worker-#81][GridCachePartitionExchangeManager] Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion [topVer=1139, minorTopVer=0], force=true, evt=DISCOVERY_CUSTOM_EVT, node=aa6bfd45-5c9a-4c61-84d2-588ef0af3265]
[05:57:16,193][SEVERE][sys-stripe-15-#16][] 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=CRITICAL_ERROR, err=java.lang.NullPointerException]]
java.lang.NullPointerException
at org.apache.ignite.internal.processors.cache.transactions.IgniteTxHandler.finishDhtLocal(IgniteTxHandler.java:1064)
at org.apache.ignite.internal.processors.cache.transactions.IgniteTxHandler.finish(IgniteTxHandler.java:953)
at org.apache.ignite.internal.processors.cache.transactions.IgniteTxHandler.processNearTxFinishRequest(IgniteTxHandler.java:909)
at org.apache.ignite.internal.processors.cache.transactions.IgniteTxHandler.access$200(IgniteTxHandler.java:123)
at org.apache.ignite.internal.processors.cache.transactions.IgniteTxHandler$3.apply(IgniteTxHandler.java:217)
at org.apache.ignite.internal.processors.cache.transactions.IgniteTxHandler$3.apply(IgniteTxHandler.java:215)
at org.apache.ignite.internal.processors.cache.GridCacheIoManager.processMessage(GridCacheIoManager.java:1142)
at org.apache.ignite.internal.processors.cache.GridCacheIoManager.onMessage0(GridCacheIoManager.java:591)
at org.apache.ignite.internal.processors.cache.GridCacheIoManager.handleMessage(GridCacheIoManager.java:392)
at org.apache.ignite.internal.processors.cache.GridCacheIoManager.handleMessage(GridCacheIoManager.java:318)
at org.apache.ignite.internal.processors.cache.GridCacheIoManager.access$100(GridCacheIoManager.java:109)
at org.apache.ignite.internal.processors.cache.GridCacheIoManager$1.onMessage(GridCacheIoManager.java:308)
at org.apache.ignite.internal.managers.communication.GridIoManager.invokeListener(GridIoManager.java:1847)
at org.apache.ignite.internal.managers.communication.GridIoManager.processRegularMessage0(GridIoManager.java:1472)
at org.apache.ignite.internal.managers.communication.GridIoManager.access$5200(GridIoManager.java:229)
at org.apache.ignite.internal.managers.communication.GridIoManager$9.run(GridIoManager.java:1367)
at org.apache.ignite.internal.util.StripedExecutor$Stripe.body(StripedExecutor.java:565)
at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
at java.lang.Thread.run(Thread.java:745)
[05:57:16,495][WARNING][sys-stripe-15-#16][CacheDiagnosticManager] Page locks dump:

Thread=[name=auth-#69, id=119], state=WAITING
Locked pages = []
Locked pages log: name=auth-#69 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=checkpoint-runner-#109, id=163], state=WAITING
Locked pages = []
Locked pages log: name=checkpoint-runner-#109 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=checkpoint-runner-#110, id=164], state=WAITING
Locked pages = []
Locked pages log: name=checkpoint-runner-#110 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=checkpoint-runner-#111, id=165], state=WAITING
Locked pages = []
Locked pages log: name=checkpoint-runner-#111 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=checkpoint-runner-#112, id=166], state=WAITING
Locked pages = []
Locked pages log: name=checkpoint-runner-#112 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=checkpoint-runner-#113, id=167], state=WAITING
Locked pages = []
Locked pages log: name=checkpoint-runner-#113 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=checkpoint-runner-#114, id=168], state=WAITING
Locked pages = []
Locked pages log: name=checkpoint-runner-#114 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=checkpoint-runner-#115, id=169], state=WAITING
Locked pages = []
Locked pages log: name=checkpoint-runner-#115 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=checkpoint-runner-#116, id=170], state=WAITING
Locked pages = []
Locked pages log: name=checkpoint-runner-#116 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=client-connector-#2504, id=2675], state=WAITING
Locked pages = []
Locked pages log: name=client-connector-#2504 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=client-connector-#2506, id=2677], state=WAITING
Locked pages = []
Locked pages log: name=client-connector-#2506 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=client-connector-#2508, id=2679], state=WAITING
Locked pages = []
Locked pages log: name=client-connector-#2508 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=client-connector-#2509, id=2680], state=WAITING
Locked pages = []
Locked pages log: name=client-connector-#2509 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=client-connector-#2510, id=2681], state=WAITING
Locked pages = []
Locked pages log: name=client-connector-#2510 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=client-connector-#2511, id=2682], state=WAITING
Locked pages = []
Locked pages log: name=client-connector-#2511 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=client-connector-#2513, id=2684], state=WAITING
Locked pages = []
Locked pages log: name=client-connector-#2513 time=(1599026236195, 2020-09-02 05:57:16.195)


Thread=[name=client-connector-#2515, id=2686], state=WAITING
Locked pages = []
Locked pages log: name=client-connector-#2515 time=(1599026236195, 2020-09-02 05:57:16.195)


Thread=[name=client-connector-#2516, id=2687], state=WAITING
Locked pages = []
Locked pages log: name=client-connector-#2516 time=(1599026236195, 2020-09-02 05:57:16.195)


Thread=[name=client-connector-#2517, id=2688], state=WAITING
Locked pages = []
Locked pages log: name=client-connector-#2517 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=client-connector-#2518, id=2689], state=WAITING
Locked pages = []
Locked pages log: name=client-connector-#2518 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=client-connector-#2519, id=2690], state=WAITING
Locked pages = []
Locked pages log: name=client-connector-#2519 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=client-connector-#2520, id=2691], state=WAITING
Locked pages = []
Locked pages log: name=client-connector-#2520 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=client-connector-#2522, id=2693], state=WAITING
Locked pages = []
Locked pages log: name=client-connector-#2522 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=client-connector-#2523, id=2694], state=WAITING
Locked pages = []
Locked pages log: name=client-connector-#2523 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=client-connector-#2524, id=2695], state=WAITING
Locked pages = []
Locked pages log: name=client-connector-#2524 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=db-checkpoint-thread-#108, id=162], state=TIMED_WAITING
Locked pages = []
Locked pages log: name=db-checkpoint-thread-#108 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=dms-writer-thread-#85, id=137], state=WAITING
Locked pages = []
Locked pages log: name=dms-writer-thread-#85 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=exchange-worker-#81, id=133], state=RUNNABLE
Locked pages = []
Locked pages log: name=exchange-worker-#81 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=main, id=1], state=WAITING
Locked pages = []
Locked pages log: name=main time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-0-#1, id=20], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-0-#1 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-1-#2, id=21], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-1-#2 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-10-#11, id=30], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-10-#11 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-11-#12, id=31], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-11-#12 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-12-#13, id=32], state=BLOCKED
Locked pages = []
Locked pages log: name=sys-stripe-12-#13 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-13-#14, id=33], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-13-#14 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-14-#15, id=34], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-14-#15 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-15-#16, id=35], state=RUNNABLE
Locked pages = []
Locked pages log: name=sys-stripe-15-#16 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-16-#17, id=36], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-16-#17 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-17-#18, id=37], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-17-#18 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-18-#19, id=38], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-18-#19 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-19-#20, id=39], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-19-#20 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-2-#3, id=22], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-2-#3 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-20-#21, id=40], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-20-#21 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-21-#22, id=41], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-21-#22 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-22-#23, id=42], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-22-#23 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-23-#24, id=43], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-23-#24 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-24-#25, id=44], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-24-#25 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-25-#26, id=45], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-25-#26 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-26-#27, id=46], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-26-#27 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-27-#28, id=47], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-27-#28 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-28-#29, id=48], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-28-#29 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-29-#30, id=49], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-29-#30 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-3-#4, id=23], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-3-#4 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-30-#31, id=50], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-30-#31 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-31-#32, id=51], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-31-#32 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-4-#5, id=24], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-4-#5 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-5-#6, id=25], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-5-#6 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-6-#7, id=26], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-6-#7 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-7-#8, id=27], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-7-#8 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-8-#9, id=28], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-8-#9 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=sys-stripe-9-#10, id=29], state=WAITING
Locked pages = []
Locked pages log: name=sys-stripe-9-#10 time=(1599026236194, 2020-09-02 05:57:16.194)


Thread=[name=ttl-cleanup-worker-#107, id=159], state=TIMED_WAITING
Locked pages = []
Locked pages log: name=ttl-cleanup-worker-#107 time=(1599026236194, 2020-09-02 05:57:16.194)



[05:57:16,495][SEVERE][sys-stripe-15-#16][] JVM will be halted immediately due to the failure: [failureCtx=FailureContext [type=CRITICAL_ERROR, err=java.lang.NullPointerException]]
[root@ns2 log]#




Mahesh Renduchintala Mahesh Renduchintala
Reply | Threaded
Open this post in threaded view
|

Re: Ignite 2.81. - NULL pointer exception

In reply to this post by ilya.kasnacheev
I sent the logs again. There is no specific activity. 
We have a cluster - 2 servers and about 15 thick clients
Just happened without much info. I can say it is likely a new node joined in and it may have triggered this crash.


ilya.kasnacheev ilya.kasnacheev
Reply | Threaded
Open this post in threaded view
|

Re: Ignite 2.81. - NULL pointer exception

Hello!

I wonder why there's no stack traces for all the threads.

I wonder if somebody from the development side will step in (2.8.1):

[05:57:16,193][SEVERE][sys-stripe-15-#16][] 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=CRITICAL_ERROR, err=java.lang.NullPointerException]]
java.lang.NullPointerException
at org.apache.ignite.internal.processors.cache.transactions.IgniteTxHandler.finishDhtLocal(IgniteTxHandler.java:1064) // tx is null?
at org.apache.ignite.internal.processors.cache.transactions.IgniteTxHandler.finish(IgniteTxHandler.java:953)
at org.apache.ignite.internal.processors.cache.transactions.IgniteTxHandler.processNearTxFinishRequest(IgniteTxHandler.java:909)
at org.apache.ignite.internal.processors.cache.transactions.IgniteTxHandler.access$200(IgniteTxHandler.java:123)
at org.apache.ignite.internal.processors.cache.transactions.IgniteTxHandler$3.apply(IgniteTxHandler.java:217)
at org.apache.ignite.internal.processors.cache.transactions.IgniteTxHandler$3.apply(IgniteTxHandler.java:215)
at org.apache.ignite.internal.processors.cache.GridCacheIoManager.processMessage(GridCacheIoManager.java:1142)
at org.apache.ignite.internal.processors.cache.GridCacheIoManager.onMessage0(GridCacheIoManager.java:591)
at org.apache.ignite.internal.processors.cache.GridCacheIoManager.handleMessage(GridCacheIoManager.java:392)
at org.apache.ignite.internal.processors.cache.GridCacheIoManager.handleMessage(GridCacheIoManager.java:318)
at org.apache.ignite.internal.processors.cache.GridCacheIoManager.access$100(GridCacheIoManager.java:109)
at org.apache.ignite.internal.processors.cache.GridCacheIoManager$1.onMessage(GridCacheIoManager.java:308)
at org.apache.ignite.internal.managers.communication.GridIoManager.invokeListener(GridIoManager.java:1847)
at org.apache.ignite.internal.managers.communication.GridIoManager.processRegularMessage0(GridIoManager.java:1472)
at org.apache.ignite.internal.managers.communication.GridIoManager.access$5200(GridIoManager.java:229)
at org.apache.ignite.internal.managers.communication.GridIoManager$9.run(GridIoManager.java:1367)
at org.apache.ignite.internal.util.StripedExecutor$Stripe.body(StripedExecutor.java:565)
at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
at java.lang.Thread.run(Thread.java:745) 

Regards,
--
Ilya Kasnacheev


ср, 2 сент. 2020 г. в 11:05, Mahesh Renduchintala <[hidden email]>:
I sent the logs again. There is no specific activity. 
We have a cluster - 2 servers and about 15 thick clients
Just happened without much info. I can say it is likely a new node joined in and it may have triggered this crash.