[IGNITE-12579] JDBC SQL INSERT operation hangs with security enabled.

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Fix Version/s: 2.9
• Labels: iep-41
• Ignite Flags: Docs Required, Release Notes Required
• Assignee: Mikhail Petrov
• Reporter: Mikhail Petrov
• Created: 24/Jan/20 12:13
• Updated: 19/May/20 08:13
• Resolved: 14/May/20 07:10

Description

 

SQL INSERT operation hangs in case INSERT KEY belongs to remote node(node that is different from one to which jdbc connection was established) and security enabled with the following exception in log:

[2020-01-24 14:59:42,189][ERROR][sys-stripe-4-#48%jdbc.JdbcRemoteKeyInsertTest1%][IgniteTestResources] Critical system error detected. Will be handled accordingly to configured handler [hnd=NoOpFailureHandler [super=AbstractFailureHandler [ignoredFailureTypes=UnmodifiableSet [SYSTEM_WORKER_BLOCKED, SYSTEM_CRITICAL_OPERATION_TIMEOUT]]], failureCtx=FailureContext [type=SYSTEM_WORKER_TERMINATION, err=java.lang.NullPointerException]][2020-01-24 14:59:42,189][ERROR][sys-stripe-4-#48%jdbc.JdbcRemoteKeyInsertTest1%][IgniteTestResources] Critical system error detected. Will be handled accordingly to configured handler [hnd=NoOpFailureHandler [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.internal.processors.security.SecurityUtils.nodeSecurityContext(SecurityUtils.java:132) at org.apache.ignite.internal.processors.security.IgniteSecurityProcessor.lambda$withContext$0(IgniteSecurityProcessor.java:106) at java.util.concurrent.ConcurrentHashMap.computeIfAbsent(ConcurrentHashMap.java:1660) at org.apache.ignite.internal.processors.security.IgniteSecurityProcessor.withContext(IgniteSecurityProcessor.java:105) at org.apache.ignite.internal.managers.communication.GridIoManager.invokeListener(GridIoManager.java:1844) at org.apache.ignite.internal.managers.communication.GridIoManager.processRegularMessage0(GridIoManager.java:1470) 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:1365) 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:748)[2020-01-24 14:59:42,198][WARN ][sys-stripe-4-#48%jdbc.JdbcRemoteKeyInsertTest1%][CacheDiagnosticManager] Page locks dump:
Thread=[name=auth-#83%jdbc.JdbcRemoteKeyInsertTest1%, id=116], state=WAITINGLocked pages = []Locked pages log: name=auth-#83%jdbc.JdbcRemoteKeyInsertTest1% time=(1579867182194, 2020-01-24 14:59:42.194)Thread=[name=db-checkpoint-thread-#101%jdbc.JdbcRemoteKeyInsertTest1%, id=135], state=TIMED_WAITINGLocked pages = []Locked pages log: name=db-checkpoint-thread-#101%jdbc.JdbcRemoteKeyInsertTest1% time=(1579867182194, 2020-01-24 14:59:42.194)Thread=[name=dms-writer-thread-#92%jdbc.JdbcRemoteKeyInsertTest1%, id=126], state=WAITINGLocked pages = []Locked pages log: name=dms-writer-thread-#92%jdbc.JdbcRemoteKeyInsertTest1% time=(1579867182194, 2020-01-24 14:59:42.194)Thread=[name=exchange-worker-#84%jdbc.JdbcRemoteKeyInsertTest1%, id=117], state=TIMED_WAITINGLocked pages = []Locked pages log: name=exchange-worker-#84%jdbc.JdbcRemoteKeyInsertTest1% time=(1579867182194, 2020-01-24 14:59:42.194)Thread=[name=main, id=1], state=TIMED_WAITINGLocked pages = []Locked pages log: name=main time=(1579867182193, 2020-01-24 14:59:42.193)
[2020-01-24 14:59:42,198][ERROR][sys-stripe-4-#48%jdbc.JdbcRemoteKeyInsertTest1%][G] Failed to execute runnable.java.lang.NullPointerException at org.apache.ignite.internal.processors.security.SecurityUtils.nodeSecurityContext(SecurityUtils.java:132) at org.apache.ignite.internal.processors.security.IgniteSecurityProcessor.lambda$withContext$0(IgniteSecurityProcessor.java:106) at java.util.concurrent.ConcurrentHashMap.computeIfAbsent(ConcurrentHashMap.java:1660) at org.apache.ignite.internal.processors.security.IgniteSecurityProcessor.withContext(IgniteSecurityProcessor.java:105) at org.apache.ignite.internal.managers.communication.GridIoManager.invokeListener(GridIoManager.java:1844) at org.apache.ignite.internal.managers.communication.GridIoManager.processRegularMessage0(GridIoManager.java:1470) 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:1365) 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:748)

 Reproducer is attached to the ticket.

It seems that a remote node while sql execution receives a security context with a subject id equals to the JDBC client id.  And during authorization process this id is used  for the node ATTR_SECURITY_SUBJECT_V2 obtaining (IgniteSecurityProcessor:107). This causes the mentioned above NPE.

UPD The root cause of described above issue has been fixed by IGNITE-12759. The current ticket requires tests to confirm that the problem has been solved in this particular case.

 

 

Issue Links

• fixes: IGNITE-12833 JDBC thin client SELECT hangs under 2.8.0
• is caused by: IGNITE-12589 Remote thin client operations are not authorized correctly.
• is related to: IGNITE-12759 Getting a SecurityContext from GridSecurityProcessor
• links to: GitHub Pull Request #7691