cassandra-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Jaydeepkumar Chovatia (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (CASSANDRA-13768) auth_test.py dtest fails intermittently due to thread race condition
Date Wed, 16 Aug 2017 21:03:00 GMT

     [ https://issues.apache.org/jira/browse/CASSANDRA-13768?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]

Jaydeepkumar Chovatia updated CASSANDRA-13768:
----------------------------------------------
    Description: 
*Root cause:* dtest {{auth_test.TestAuth.system_auth_ks_is_alterable_test}} is failing intermittently
and it is due to race condition between Python driver continuously sending cql query (by thread
t1) to know status of cluster, and {{ccm}} is stopping the nodes (by thread t2)

*Failure details:* http://cassci.datastax.com/view/cassandra-3.0/job/cassandra-3.0_dtest/lastCompletedBuild/testReport/auth_test/TestAuth/system_auth_ks_is_alterable_test/
*Solution:* Ignore {{UnavailableException}} for this particular test as it is not going to
harm test case in anyway.
Please find snippet of C* log when test fails:
{{INFO [InternalResponseStage:8] 2017-08-15 10:44:13,213 RepairRunnable.java:337 - Repair
command #2 finished in 0 seconds INFO [GossipStage:1] 2017-08-15 10:44:13,601 Gossiper.java:1019
- InetAddress /127.0.0.1 is now DOWN INFO [HANDSHAKE-/127.0.0.1] 2017-08-15 10:44:13,715 OutboundTcpConnection.java:564
- Handshaking version with /127.0.0.1 INFO [SharedPool-Worker-2] 2017-08-15 10:44:16,712 Message.java:512
- Received: OPTIONS, v=4 INFO [SharedPool-Worker-2] 2017-08-15 10:44:16,713 Message.java:512
- Received: STARTUP {CQL_VERSION=3.4.0, COMPRESSION=snappy}, v=4 INFO [SharedPool-Worker-2]
2017-08-15 10:44:16,719 Message.java:512 - Received: org.apache.cassandra.transport.messages.AuthResponse@4474c719,
v=4 INFO [GossipStage:1] 2017-08-15 10:44:16,723 Gossiper.java:1019 - InetAddress /127.0.0.3
is now DOWN ERROR [SharedPool-Worker-2] 2017-08-15 10:44:16,822 Message.java:621 - Unexpected
exception during request; channel = [id: 0xffc2fc9a, L:/127.0.0.2:9042 - R:/127.0.0.2:51369]
java.lang.RuntimeException: org.apache.cassandra.exceptions.UnavailableException: Cannot achieve
consistency level QUORUM at org.apache.cassandra.auth.CassandraRoleManager.getRole(CassandraRoleManager.java:516)
~[main/:na] at org.apache.cassandra.auth.CassandraRoleManager.canLogin(CassandraRoleManager.java:310)
~[main/:na] at org.apache.cassandra.service.ClientState.login(ClientState.java:270) ~[main/:na]
at org.apache.cassandra.transport.messages.AuthResponse.execute(AuthResponse.java:79) ~[main/:na]
at org.apache.cassandra.transport.Message$Dispatcher.channelRead0(Message.java:513) [main/:na]
at org.apache.cassandra.transport.Message$Dispatcher.channelRead0(Message.java:407) [main/:na]
at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:105)
[netty-all-4.0.44.Final.jar:4.0.44.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:357)
[netty-all-4.0.44.Final.jar:4.0.44.Final] at io.netty.channel.AbstractChannelHandlerContext.access$600(AbstractChannelHandlerContext.java:35)
[netty-all-4.0.44.Final.jar:4.0.44.Final] at io.netty.channel.AbstractChannelHandlerContext$7.run(AbstractChannelHandlerContext.java:348)
[netty-all-4.0.44.Final.jar:4.0.44.Final] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[na:1.8.0_144] at org.apache.cassandra.concurrent.AbstractLocalAwareExecutorService$FutureTask.run(AbstractLocalAwareExecutorService.java:164)
[main/:na] at org.apache.cassandra.concurrent.SEPWorker.run(SEPWorker.java:105) [main/:na]
at java.lang.Thread.run(Thread.java:748) [na:1.8.0_144] Caused by: org.apache.cassandra.exceptions.UnavailableException:
Cannot achieve consistency level QUORUM at org.apache.cassandra.db.ConsistencyLevel.assureSufficientLiveNodes(ConsistencyLevel.java:334)
~[main/:na] at org.apache.cassandra.service.AbstractReadExecutor.getReadExecutor(AbstractReadExecutor.java:162)
~[main/:na] at org.apache.cassandra.service.StorageProxy$SinglePartitionReadLifecycle.<init>(StorageProxy.java:1733)
~[main/:na] at org.apache.cassandra.service.StorageProxy.fetchRows(StorageProxy.java:1696)
~[main/:na] at org.apache.cassandra.service.StorageProxy.readRegular(StorageProxy.java:1640)
~[main/:na] at org.apache.cassandra.service.StorageProxy.read(StorageProxy.java:1544) ~[main/:na]
at org.apache.cassandra.db.SinglePartitionReadCommand$Group.execute(SinglePartitionReadCommand.java:965)
~[main/:na] at org.apache.cassandra.cql3.statements.SelectStatement.execute(SelectStatement.java:263)
~[main/:na] at org.apache.cassandra.cql3.statements.SelectStatement.execute(SelectStatement.java:224)
~[main/:na] at org.apache.cassandra.auth.CassandraRoleManager.getRoleFromTable(CassandraRoleManager.java:524)
~[main/:na] at org.apache.cassandra.auth.CassandraRoleManager.getRole(CassandraRoleManager.java:506)
~[main/:na] ... 13 common frames omitted INFO [HANDSHAKE-/127.0.0.3] 2017-08-15 10:44:17,678
OutboundTcpConnection.java:564 - Handshaking version with /127.0.0.3 INFO [SharedPool-Worker-1]
2017-08-15 10:44:17,927 Message.java:512 - Received: OPTIONS, v=4 INFO [SharedPool-Worker-1]
2017-08-15 10:44:17,928 Message.java:512 - Received: STARTUP {CQL_VERSION=3.4.0, COMPRESSION=snappy},
v=4 INFO [SharedPool-Worker-2] 2017-08-15 10:44:17,932 Message.java:512 - Received: org.apache.cassandra.transport.messages.AuthResponse@3cc2a95c,
v=4 INFO [StorageServiceShutdownHook] 2017-08-15 10:44:19,814 HintsService.java:212 - Paused
hints dispatch INFO [StorageServiceShutdownHook] 2017-08-15 10:44:19,818 Server.java:180 -
Stop listening for CQL clients INFO [StorageServiceShutdownHook] 2017-08-15 10:44:19,818 Gossiper.java:1490
- Announcing shutdown INFO [StorageServiceShutdownHook] 2017-08-15 10:44:19,819 StorageService.java:2011
- Node /127.0.0.2 state jump to shutdown}}

  was:
*Root cause:* dtest {{auth_test.TestAuth.system_auth_ks_is_alterable_test }} is failing intermittently
and it is due to race condition between Python driver continuously sending cql query (by thread
t1) to know status of cluster, and {{ccm}} is stopping the nodes (by thread t2)

*Failure details:* http://cassci.datastax.com/view/cassandra-3.0/job/cassandra-3.0_dtest/lastCompletedBuild/testReport/auth_test/TestAuth/system_auth_ks_is_alterable_test/
*Solution:* Ignore {{UnavailableException}} for this particular test as it is not going to
harm test case in anyway.
Please find snippet of C* log when test fails:
{{INFO [InternalResponseStage:8] 2017-08-15 10:44:13,213 RepairRunnable.java:337 - Repair
command #2 finished in 0 seconds INFO [GossipStage:1] 2017-08-15 10:44:13,601 Gossiper.java:1019
- InetAddress /127.0.0.1 is now DOWN INFO [HANDSHAKE-/127.0.0.1] 2017-08-15 10:44:13,715 OutboundTcpConnection.java:564
- Handshaking version with /127.0.0.1 INFO [SharedPool-Worker-2] 2017-08-15 10:44:16,712 Message.java:512
- Received: OPTIONS, v=4 INFO [SharedPool-Worker-2] 2017-08-15 10:44:16,713 Message.java:512
- Received: STARTUP {CQL_VERSION=3.4.0, COMPRESSION=snappy}, v=4 INFO [SharedPool-Worker-2]
2017-08-15 10:44:16,719 Message.java:512 - Received: org.apache.cassandra.transport.messages.AuthResponse@4474c719,
v=4 INFO [GossipStage:1] 2017-08-15 10:44:16,723 Gossiper.java:1019 - InetAddress /127.0.0.3
is now DOWN ERROR [SharedPool-Worker-2] 2017-08-15 10:44:16,822 Message.java:621 - Unexpected
exception during request; channel = [id: 0xffc2fc9a, L:/127.0.0.2:9042 - R:/127.0.0.2:51369]
java.lang.RuntimeException: org.apache.cassandra.exceptions.UnavailableException: Cannot achieve
consistency level QUORUM at org.apache.cassandra.auth.CassandraRoleManager.getRole(CassandraRoleManager.java:516)
~[main/:na] at org.apache.cassandra.auth.CassandraRoleManager.canLogin(CassandraRoleManager.java:310)
~[main/:na] at org.apache.cassandra.service.ClientState.login(ClientState.java:270) ~[main/:na]
at org.apache.cassandra.transport.messages.AuthResponse.execute(AuthResponse.java:79) ~[main/:na]
at org.apache.cassandra.transport.Message$Dispatcher.channelRead0(Message.java:513) [main/:na]
at org.apache.cassandra.transport.Message$Dispatcher.channelRead0(Message.java:407) [main/:na]
at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:105)
[netty-all-4.0.44.Final.jar:4.0.44.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:357)
[netty-all-4.0.44.Final.jar:4.0.44.Final] at io.netty.channel.AbstractChannelHandlerContext.access$600(AbstractChannelHandlerContext.java:35)
[netty-all-4.0.44.Final.jar:4.0.44.Final] at io.netty.channel.AbstractChannelHandlerContext$7.run(AbstractChannelHandlerContext.java:348)
[netty-all-4.0.44.Final.jar:4.0.44.Final] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[na:1.8.0_144] at org.apache.cassandra.concurrent.AbstractLocalAwareExecutorService$FutureTask.run(AbstractLocalAwareExecutorService.java:164)
[main/:na] at org.apache.cassandra.concurrent.SEPWorker.run(SEPWorker.java:105) [main/:na]
at java.lang.Thread.run(Thread.java:748) [na:1.8.0_144] Caused by: org.apache.cassandra.exceptions.UnavailableException:
Cannot achieve consistency level QUORUM at org.apache.cassandra.db.ConsistencyLevel.assureSufficientLiveNodes(ConsistencyLevel.java:334)
~[main/:na] at org.apache.cassandra.service.AbstractReadExecutor.getReadExecutor(AbstractReadExecutor.java:162)
~[main/:na] at org.apache.cassandra.service.StorageProxy$SinglePartitionReadLifecycle.<init>(StorageProxy.java:1733)
~[main/:na] at org.apache.cassandra.service.StorageProxy.fetchRows(StorageProxy.java:1696)
~[main/:na] at org.apache.cassandra.service.StorageProxy.readRegular(StorageProxy.java:1640)
~[main/:na] at org.apache.cassandra.service.StorageProxy.read(StorageProxy.java:1544) ~[main/:na]
at org.apache.cassandra.db.SinglePartitionReadCommand$Group.execute(SinglePartitionReadCommand.java:965)
~[main/:na] at org.apache.cassandra.cql3.statements.SelectStatement.execute(SelectStatement.java:263)
~[main/:na] at org.apache.cassandra.cql3.statements.SelectStatement.execute(SelectStatement.java:224)
~[main/:na] at org.apache.cassandra.auth.CassandraRoleManager.getRoleFromTable(CassandraRoleManager.java:524)
~[main/:na] at org.apache.cassandra.auth.CassandraRoleManager.getRole(CassandraRoleManager.java:506)
~[main/:na] ... 13 common frames omitted INFO [HANDSHAKE-/127.0.0.3] 2017-08-15 10:44:17,678
OutboundTcpConnection.java:564 - Handshaking version with /127.0.0.3 INFO [SharedPool-Worker-1]
2017-08-15 10:44:17,927 Message.java:512 - Received: OPTIONS, v=4 INFO [SharedPool-Worker-1]
2017-08-15 10:44:17,928 Message.java:512 - Received: STARTUP {CQL_VERSION=3.4.0, COMPRESSION=snappy},
v=4 INFO [SharedPool-Worker-2] 2017-08-15 10:44:17,932 Message.java:512 - Received: org.apache.cassandra.transport.messages.AuthResponse@3cc2a95c,
v=4 INFO [StorageServiceShutdownHook] 2017-08-15 10:44:19,814 HintsService.java:212 - Paused
hints dispatch INFO [StorageServiceShutdownHook] 2017-08-15 10:44:19,818 Server.java:180 -
Stop listening for CQL clients INFO [StorageServiceShutdownHook] 2017-08-15 10:44:19,818 Gossiper.java:1490
- Announcing shutdown INFO [StorageServiceShutdownHook] 2017-08-15 10:44:19,819 StorageService.java:2011
- Node /127.0.0.2 state jump to shutdown}}


> auth_test.py dtest fails intermittently due to thread race condition
> --------------------------------------------------------------------
>
>                 Key: CASSANDRA-13768
>                 URL: https://issues.apache.org/jira/browse/CASSANDRA-13768
>             Project: Cassandra
>          Issue Type: Bug
>          Components: Testing
>            Reporter: Jaydeepkumar Chovatia
>            Priority: Minor
>
> *Root cause:* dtest {{auth_test.TestAuth.system_auth_ks_is_alterable_test}} is failing
intermittently and it is due to race condition between Python driver continuously sending
cql query (by thread t1) to know status of cluster, and {{ccm}} is stopping the nodes (by
thread t2)
> *Failure details:* http://cassci.datastax.com/view/cassandra-3.0/job/cassandra-3.0_dtest/lastCompletedBuild/testReport/auth_test/TestAuth/system_auth_ks_is_alterable_test/
> *Solution:* Ignore {{UnavailableException}} for this particular test as it is not going
to harm test case in anyway.
> Please find snippet of C* log when test fails:
> {{INFO [InternalResponseStage:8] 2017-08-15 10:44:13,213 RepairRunnable.java:337 - Repair
command #2 finished in 0 seconds INFO [GossipStage:1] 2017-08-15 10:44:13,601 Gossiper.java:1019
- InetAddress /127.0.0.1 is now DOWN INFO [HANDSHAKE-/127.0.0.1] 2017-08-15 10:44:13,715 OutboundTcpConnection.java:564
- Handshaking version with /127.0.0.1 INFO [SharedPool-Worker-2] 2017-08-15 10:44:16,712 Message.java:512
- Received: OPTIONS, v=4 INFO [SharedPool-Worker-2] 2017-08-15 10:44:16,713 Message.java:512
- Received: STARTUP {CQL_VERSION=3.4.0, COMPRESSION=snappy}, v=4 INFO [SharedPool-Worker-2]
2017-08-15 10:44:16,719 Message.java:512 - Received: org.apache.cassandra.transport.messages.AuthResponse@4474c719,
v=4 INFO [GossipStage:1] 2017-08-15 10:44:16,723 Gossiper.java:1019 - InetAddress /127.0.0.3
is now DOWN ERROR [SharedPool-Worker-2] 2017-08-15 10:44:16,822 Message.java:621 - Unexpected
exception during request; channel = [id: 0xffc2fc9a, L:/127.0.0.2:9042 - R:/127.0.0.2:51369]
java.lang.RuntimeException: org.apache.cassandra.exceptions.UnavailableException: Cannot achieve
consistency level QUORUM at org.apache.cassandra.auth.CassandraRoleManager.getRole(CassandraRoleManager.java:516)
~[main/:na] at org.apache.cassandra.auth.CassandraRoleManager.canLogin(CassandraRoleManager.java:310)
~[main/:na] at org.apache.cassandra.service.ClientState.login(ClientState.java:270) ~[main/:na]
at org.apache.cassandra.transport.messages.AuthResponse.execute(AuthResponse.java:79) ~[main/:na]
at org.apache.cassandra.transport.Message$Dispatcher.channelRead0(Message.java:513) [main/:na]
at org.apache.cassandra.transport.Message$Dispatcher.channelRead0(Message.java:407) [main/:na]
at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:105)
[netty-all-4.0.44.Final.jar:4.0.44.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:357)
[netty-all-4.0.44.Final.jar:4.0.44.Final] at io.netty.channel.AbstractChannelHandlerContext.access$600(AbstractChannelHandlerContext.java:35)
[netty-all-4.0.44.Final.jar:4.0.44.Final] at io.netty.channel.AbstractChannelHandlerContext$7.run(AbstractChannelHandlerContext.java:348)
[netty-all-4.0.44.Final.jar:4.0.44.Final] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[na:1.8.0_144] at org.apache.cassandra.concurrent.AbstractLocalAwareExecutorService$FutureTask.run(AbstractLocalAwareExecutorService.java:164)
[main/:na] at org.apache.cassandra.concurrent.SEPWorker.run(SEPWorker.java:105) [main/:na]
at java.lang.Thread.run(Thread.java:748) [na:1.8.0_144] Caused by: org.apache.cassandra.exceptions.UnavailableException:
Cannot achieve consistency level QUORUM at org.apache.cassandra.db.ConsistencyLevel.assureSufficientLiveNodes(ConsistencyLevel.java:334)
~[main/:na] at org.apache.cassandra.service.AbstractReadExecutor.getReadExecutor(AbstractReadExecutor.java:162)
~[main/:na] at org.apache.cassandra.service.StorageProxy$SinglePartitionReadLifecycle.<init>(StorageProxy.java:1733)
~[main/:na] at org.apache.cassandra.service.StorageProxy.fetchRows(StorageProxy.java:1696)
~[main/:na] at org.apache.cassandra.service.StorageProxy.readRegular(StorageProxy.java:1640)
~[main/:na] at org.apache.cassandra.service.StorageProxy.read(StorageProxy.java:1544) ~[main/:na]
at org.apache.cassandra.db.SinglePartitionReadCommand$Group.execute(SinglePartitionReadCommand.java:965)
~[main/:na] at org.apache.cassandra.cql3.statements.SelectStatement.execute(SelectStatement.java:263)
~[main/:na] at org.apache.cassandra.cql3.statements.SelectStatement.execute(SelectStatement.java:224)
~[main/:na] at org.apache.cassandra.auth.CassandraRoleManager.getRoleFromTable(CassandraRoleManager.java:524)
~[main/:na] at org.apache.cassandra.auth.CassandraRoleManager.getRole(CassandraRoleManager.java:506)
~[main/:na] ... 13 common frames omitted INFO [HANDSHAKE-/127.0.0.3] 2017-08-15 10:44:17,678
OutboundTcpConnection.java:564 - Handshaking version with /127.0.0.3 INFO [SharedPool-Worker-1]
2017-08-15 10:44:17,927 Message.java:512 - Received: OPTIONS, v=4 INFO [SharedPool-Worker-1]
2017-08-15 10:44:17,928 Message.java:512 - Received: STARTUP {CQL_VERSION=3.4.0, COMPRESSION=snappy},
v=4 INFO [SharedPool-Worker-2] 2017-08-15 10:44:17,932 Message.java:512 - Received: org.apache.cassandra.transport.messages.AuthResponse@3cc2a95c,
v=4 INFO [StorageServiceShutdownHook] 2017-08-15 10:44:19,814 HintsService.java:212 - Paused
hints dispatch INFO [StorageServiceShutdownHook] 2017-08-15 10:44:19,818 Server.java:180 -
Stop listening for CQL clients INFO [StorageServiceShutdownHook] 2017-08-15 10:44:19,818 Gossiper.java:1490
- Announcing shutdown INFO [StorageServiceShutdownHook] 2017-08-15 10:44:19,819 StorageService.java:2011
- Node /127.0.0.2 state jump to shutdown}}



--
This message was sent by Atlassian JIRA
(v6.4.14#64029)

---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@cassandra.apache.org
For additional commands, e-mail: commits-help@cassandra.apache.org


Mime
View raw message