[
https://issues.apache.org/jira/browse/IGNITE-12579?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Mikhail Petrov updated IGNITE-12579:
------------------------------------
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:
{code:java}
[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)
{code}
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 was fixes by
[IGNITE-12759|https://issues.apache.org/jira/browse/IGNITE-12759]. The current
ticket requires tests to confirm that the problem has been solved in this
particular case.
was:
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:
{code:java}
[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)
{code}
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.
> JDBC SQL INSERT operation hangs with security enabled.
> ------------------------------------------------------
>
> Key: IGNITE-12579
> URL: https://issues.apache.org/jira/browse/IGNITE-12579
> Project: Ignite
> Issue Type: Bug
> Reporter: Mikhail Petrov
> Priority: Major
> Labels: iep-41
> Attachments: JdbcRemoteKeyInsertTest.java
>
> Time Spent: 10m
> Remaining Estimate: 0h
>
>
> 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:
> {code:java}
> [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)
> {code}
> 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 was fixes by
> [IGNITE-12759|https://issues.apache.org/jira/browse/IGNITE-12759]. The
> current ticket requires tests to confirm that the problem has been solved in
> this particular case.
>
>
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
