[
https://issues.apache.org/jira/browse/CASSANDRA-11611?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Philip Thompson updated CASSANDRA-11611:
----------------------------------------
Issue Type: Bug (was: Test)
> dtest failure in topology_test.TestTopology.crash_during_decommission_test
> --------------------------------------------------------------------------
>
> Key: CASSANDRA-11611
> URL: https://issues.apache.org/jira/browse/CASSANDRA-11611
> Project: Cassandra
> Issue Type: Bug
> Reporter: Jim Witschey
> Assignee: DS Test Eng
> Labels: dtest
> Fix For: 3.x
>
>
> Looks like some kind of streaming error. Example failure:
> http://cassci.datastax.com/job/trunk_dtest_win32/382/testReport/topology_test/TestTopology/crash_during_decommission_test
> Failed on CassCI build trunk_dtest_win32 #382
> {code}
> Error Message
> Unexpected error in log, see stdout
> -------------------- >> begin captured logging << --------------------
> dtest: DEBUG: cluster ccm directory: d:\temp\dtest-ce_wos
> dtest: DEBUG: Custom init_config not found. Setting defaults.
> dtest: DEBUG: Done setting configuration options:
> { 'initial_token': None,
> 'num_tokens': '32',
> 'phi_convict_threshold': 5,
> 'range_request_timeout_in_ms': 10000,
> 'read_request_timeout_in_ms': 10000,
> 'request_timeout_in_ms': 10000,
> 'truncate_request_timeout_in_ms': 10000,
> 'write_request_timeout_in_ms': 10000}
> dtest: DEBUG: Status as reported by node 127.0.0.2
> dtest: DEBUG: Datacenter: datacenter1
> ========================
> Status=Up/Down
> |/ State=Normal/Leaving/Joining/Moving
> -- Address Load Tokens Owns (effective) Host ID
> Rack
> UN 127.0.0.1 98.73 KiB 32 78.4%
> b8c55c71-bf3d-462b-8c17-3c88d7ac2284 rack1
> UN 127.0.0.2 162.38 KiB 32 65.9%
> 71aacf1d-8e2f-44cf-b354-f10c71313ec6 rack1
> UN 127.0.0.3 98.71 KiB 32 55.7%
> 3a4529a3-dc7f-445c-aec3-94417c920fdf rack1
> dtest: DEBUG: Restarting node2
> dtest: DEBUG: Status as reported by node 127.0.0.2
> dtest: DEBUG: Datacenter: datacenter1
> ========================
> Status=Up/Down
> |/ State=Normal/Leaving/Joining/Moving
> -- Address Load Tokens Owns (effective) Host ID
> Rack
> UL 127.0.0.1 98.73 KiB 32 78.4%
> b8c55c71-bf3d-462b-8c17-3c88d7ac2284 rack1
> UN 127.0.0.2 222.26 KiB 32 65.9%
> 71aacf1d-8e2f-44cf-b354-f10c71313ec6 rack1
> UN 127.0.0.3 98.71 KiB 32 55.7%
> 3a4529a3-dc7f-445c-aec3-94417c920fdf rack1
> dtest: DEBUG: Restarting node2
> dtest: DEBUG: Status as reported by node 127.0.0.2
> dtest: DEBUG: Datacenter: datacenter1
> ========================
> Status=Up/Down
> |/ State=Normal/Leaving/Joining/Moving
> -- Address Load Tokens Owns (effective) Host ID
> Rack
> UL 127.0.0.1 174.2 KiB 32 78.4%
> b8c55c71-bf3d-462b-8c17-3c88d7ac2284 rack1
> UN 127.0.0.2 336.69 KiB 32 65.9%
> 71aacf1d-8e2f-44cf-b354-f10c71313ec6 rack1
> UN 127.0.0.3 116.7 KiB 32 55.7%
> 3a4529a3-dc7f-445c-aec3-94417c920fdf rack1
> dtest: DEBUG: Restarting node2
> dtest: DEBUG: Status as reported by node 127.0.0.2
> dtest: DEBUG: Datacenter: datacenter1
> ========================
> Status=Up/Down
> |/ State=Normal/Leaving/Joining/Moving
> -- Address Load Tokens Owns (effective) Host ID
> Rack
> UL 127.0.0.1 174.2 KiB 32 78.4%
> b8c55c71-bf3d-462b-8c17-3c88d7ac2284 rack1
> UN 127.0.0.2 360.82 KiB 32 65.9%
> 71aacf1d-8e2f-44cf-b354-f10c71313ec6 rack1
> UN 127.0.0.3 116.7 KiB 32 55.7%
> 3a4529a3-dc7f-445c-aec3-94417c920fdf rack1
> dtest: DEBUG: Restarting node2
> dtest: DEBUG: Status as reported by node 127.0.0.2
> dtest: DEBUG: Datacenter: datacenter1
> ========================
> Status=Up/Down
> |/ State=Normal/Leaving/Joining/Moving
> -- Address Load Tokens Owns (effective) Host ID
> Rack
> UL 127.0.0.1 174.2 KiB 32 78.4%
> b8c55c71-bf3d-462b-8c17-3c88d7ac2284 rack1
> UN 127.0.0.2 240.54 KiB 32 65.9%
> 71aacf1d-8e2f-44cf-b354-f10c71313ec6 rack1
> UN 127.0.0.3 116.7 KiB 32 55.7%
> 3a4529a3-dc7f-445c-aec3-94417c920fdf rack1
> dtest: DEBUG: Restarting node2
> dtest: DEBUG: Decommission failed with exception: Nodetool command
> 'D:\jenkins\workspace\trunk_dtest_win32\cassandra\bin\nodetool.bat -h
> localhost -p 7100 decommission' failed; exit status: 2; stderr: error: Stream
> failed
> -- StackTrace --
> org.apache.cassandra.streaming.StreamException: Stream failed
> at
> org.apache.cassandra.streaming.management.StreamEventJMXNotifier.onFailure(StreamEventJMXNotifier.java:85)
> at com.google.common.util.concurrent.Futures$6.run(Futures.java:1310)
> at
> com.google.common.util.concurrent.MoreExecutors$DirectExecutor.execute(MoreExecutors.java:457)
> at
> com.google.common.util.concurrent.ExecutionList.executeListener(ExecutionList.java:156)
> at
> com.google.common.util.concurrent.ExecutionList.execute(ExecutionList.java:145)
> at
> com.google.common.util.concurrent.AbstractFuture.setException(AbstractFuture.java:202)
> at
> org.apache.cassandra.streaming.StreamResultFuture.maybeComplete(StreamResultFuture.java:215)
> at
> org.apache.cassandra.streaming.StreamResultFuture.handleSessionComplete(StreamResultFuture.java:191)
> at
> org.apache.cassandra.streaming.StreamSession.closeSession(StreamSession.java:429)
> at
> org.apache.cassandra.streaming.StreamSession.onError(StreamSession.java:527)
> at
> org.apache.cassandra.streaming.StreamSession.start(StreamSession.java:246)
> at
> org.apache.cassandra.streaming.StreamCoordinator$StreamSessionConnector.run(StreamCoordinator.java:263)
> 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)
> dtest: DEBUG: Waiting for decommission to complete
> dtest: DEBUG: Status as reported by node 127.0.0.2
> dtest: DEBUG: Datacenter: datacenter1
> ========================
> Status=Up/Down
> |/ State=Normal/Leaving/Joining/Moving
> -- Address Load Tokens Owns (effective) Host ID
> Rack
> UL 127.0.0.1 174.2 KiB 32 78.4%
> b8c55c71-bf3d-462b-8c17-3c88d7ac2284 rack1
> UN 127.0.0.2 370.04 KiB 32 65.9%
> 71aacf1d-8e2f-44cf-b354-f10c71313ec6 rack1
> UN 127.0.0.3 116.7 KiB 32 55.7%
> 3a4529a3-dc7f-445c-aec3-94417c920fdf rack1
> dtest: DEBUG: Sleeping for 30 seconds to allow gossip updates
> dtest: DEBUG: Status as reported by node 127.0.0.2
> dtest: DEBUG: Datacenter: datacenter1
> ========================
> Status=Up/Down
> |/ State=Normal/Leaving/Joining/Moving
> -- Address Load Tokens Owns (effective) Host ID
> Rack
> UL 127.0.0.1 174.2 KiB 32 78.4%
> b8c55c71-bf3d-462b-8c17-3c88d7ac2284 rack1
> UN 127.0.0.2 370.04 KiB 32 65.9%
> 71aacf1d-8e2f-44cf-b354-f10c71313ec6 rack1
> UN 127.0.0.3 116.7 KiB 32 55.7%
> 3a4529a3-dc7f-445c-aec3-94417c920fdf rack1
> dtest: DEBUG: removing ccm cluster test at: d:\temp\dtest-ce_wos
> dtest: DEBUG: clearing ssl stores from [d:\temp\dtest-ce_wos] directory
> --------------------- >> end captured logging << ---------------------
> Stacktrace
> File "C:\tools\python2\lib\unittest\case.py", line 358, in run
> self.tearDown()
> File "D:\jenkins\workspace\trunk_dtest_win32\cassandra-dtest\dtest.py",
> line 667, in tearDown
> raise AssertionError('Unexpected error in log, see stdout')
> "Unexpected error in log, see stdout\n-------------------- >> begin captured
> logging << --------------------\ndtest: DEBUG: cluster ccm directory:
> d:\\temp\\dtest-ce_wos\ndtest: DEBUG: Custom init_config not found. Setting
> defaults.\ndtest: DEBUG: Done setting configuration options:\n{
> 'initial_token': None,\n 'num_tokens': '32',\n 'phi_convict_threshold':
> 5,\n 'range_request_timeout_in_ms': 10000,\n
> 'read_request_timeout_in_ms': 10000,\n 'request_timeout_in_ms': 10000,\n
> 'truncate_request_timeout_in_ms': 10000,\n 'write_request_timeout_in_ms':
> 10000}\ndtest: DEBUG: Status as reported by node 127.0.0.2\ndtest: DEBUG:
> Datacenter: datacenter1\n========================\nStatus=Up/Down\n|/
> State=Normal/Leaving/Joining/Moving\n-- Address Load Tokens
> Owns (effective) Host ID Rack\nUN 127.0.0.1
> 98.73 KiB 32 78.4%
> b8c55c71-bf3d-462b-8c17-3c88d7ac2284 rack1\nUN 127.0.0.2 162.38 KiB 32
> 65.9% 71aacf1d-8e2f-44cf-b354-f10c71313ec6 rack1\nUN
> 127.0.0.3 98.71 KiB 32 55.7%
> 3a4529a3-dc7f-445c-aec3-94417c920fdf rack1\n\n\ndtest: DEBUG: Restarting
> node2\ndtest: DEBUG: Status as reported by node 127.0.0.2\ndtest: DEBUG:
> Datacenter: datacenter1\n========================\nStatus=Up/Down\n|/
> State=Normal/Leaving/Joining/Moving\n-- Address Load Tokens
> Owns (effective) Host ID Rack\nUL 127.0.0.1
> 98.73 KiB 32 78.4%
> b8c55c71-bf3d-462b-8c17-3c88d7ac2284 rack1\nUN 127.0.0.2 222.26 KiB 32
> 65.9% 71aacf1d-8e2f-44cf-b354-f10c71313ec6 rack1\nUN
> 127.0.0.3 98.71 KiB 32 55.7%
> 3a4529a3-dc7f-445c-aec3-94417c920fdf rack1\n\n\ndtest: DEBUG: Restarting
> node2\ndtest: DEBUG: Status as reported by node 127.0.0.2\ndtest: DEBUG:
> Datacenter: datacenter1\n========================\nStatus=Up/Down\n|/
> State=Normal/Leaving/Joining/Moving\n-- Address Load Tokens
> Owns (effective) Host ID Rack\nUL 127.0.0.1
> 174.2 KiB 32 78.4%
> b8c55c71-bf3d-462b-8c17-3c88d7ac2284 rack1\nUN 127.0.0.2 336.69 KiB 32
> 65.9% 71aacf1d-8e2f-44cf-b354-f10c71313ec6 rack1\nUN
> 127.0.0.3 116.7 KiB 32 55.7%
> 3a4529a3-dc7f-445c-aec3-94417c920fdf rack1\n\n\ndtest: DEBUG: Restarting
> node2\ndtest: DEBUG: Status as reported by node 127.0.0.2\ndtest: DEBUG:
> Datacenter: datacenter1\n========================\nStatus=Up/Down\n|/
> State=Normal/Leaving/Joining/Moving\n-- Address Load Tokens
> Owns (effective) Host ID Rack\nUL 127.0.0.1
> 174.2 KiB 32 78.4%
> b8c55c71-bf3d-462b-8c17-3c88d7ac2284 rack1\nUN 127.0.0.2 360.82 KiB 32
> 65.9% 71aacf1d-8e2f-44cf-b354-f10c71313ec6 rack1\nUN
> 127.0.0.3 116.7 KiB 32 55.7%
> 3a4529a3-dc7f-445c-aec3-94417c920fdf rack1\n\n\ndtest: DEBUG: Restarting
> node2\ndtest: DEBUG: Status as reported by node 127.0.0.2\ndtest: DEBUG:
> Datacenter: datacenter1\n========================\nStatus=Up/Down\n|/
> State=Normal/Leaving/Joining/Moving\n-- Address Load Tokens
> Owns (effective) Host ID Rack\nUL 127.0.0.1
> 174.2 KiB 32 78.4%
> b8c55c71-bf3d-462b-8c17-3c88d7ac2284 rack1\nUN 127.0.0.2 240.54 KiB 32
> 65.9% 71aacf1d-8e2f-44cf-b354-f10c71313ec6 rack1\nUN
> 127.0.0.3 116.7 KiB 32 55.7%
> 3a4529a3-dc7f-445c-aec3-94417c920fdf rack1\n\n\ndtest: DEBUG: Restarting
> node2\ndtest: DEBUG: Decommission failed with exception: Nodetool command
> 'D:\\jenkins\\workspace\\trunk_dtest_win32\\cassandra\\bin\\nodetool.bat -h
> localhost -p 7100 decommission' failed; exit status: 2; stderr: error: Stream
> failed\n-- StackTrace --\norg.apache.cassandra.streaming.StreamException:
> Stream failed\n\tat
> org.apache.cassandra.streaming.management.StreamEventJMXNotifier.onFailure(StreamEventJMXNotifier.java:85)\n\tat
> com.google.common.util.concurrent.Futures$6.run(Futures.java:1310)\n\tat
> com.google.common.util.concurrent.MoreExecutors$DirectExecutor.execute(MoreExecutors.java:457)\n\tat
>
> com.google.common.util.concurrent.ExecutionList.executeListener(ExecutionList.java:156)\n\tat
>
> com.google.common.util.concurrent.ExecutionList.execute(ExecutionList.java:145)\n\tat
>
> com.google.common.util.concurrent.AbstractFuture.setException(AbstractFuture.java:202)\n\tat
>
> org.apache.cassandra.streaming.StreamResultFuture.maybeComplete(StreamResultFuture.java:215)\n\tat
>
> org.apache.cassandra.streaming.StreamResultFuture.handleSessionComplete(StreamResultFuture.java:191)\n\tat
>
> org.apache.cassandra.streaming.StreamSession.closeSession(StreamSession.java:429)\n\tat
>
> org.apache.cassandra.streaming.StreamSession.onError(StreamSession.java:527)\n\tat
>
> org.apache.cassandra.streaming.StreamSession.start(StreamSession.java:246)\n\tat
>
> org.apache.cassandra.streaming.StreamCoordinator$StreamSessionConnector.run(StreamCoordinator.java:263)\n\tat
>
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)\n\tat
>
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)\n\tat
> java.lang.Thread.run(Thread.java:745)\n\n\ndtest: DEBUG: Waiting for
> decommission to complete\ndtest: DEBUG: Status as reported by node
> 127.0.0.2\ndtest: DEBUG: Datacenter:
> datacenter1\n========================\nStatus=Up/Down\n|/
> State=Normal/Leaving/Joining/Moving\n-- Address Load Tokens
> Owns (effective) Host ID Rack\nUL 127.0.0.1
> 174.2 KiB 32 78.4%
> b8c55c71-bf3d-462b-8c17-3c88d7ac2284 rack1\nUN 127.0.0.2 370.04 KiB 32
> 65.9% 71aacf1d-8e2f-44cf-b354-f10c71313ec6 rack1\nUN
> 127.0.0.3 116.7 KiB 32 55.7%
> 3a4529a3-dc7f-445c-aec3-94417c920fdf rack1\n\n\ndtest: DEBUG: Sleeping for
> 30 seconds to allow gossip updates\ndtest: DEBUG: Status as reported by node
> 127.0.0.2\ndtest: DEBUG: Datacenter:
> datacenter1\n========================\nStatus=Up/Down\n|/
> State=Normal/Leaving/Joining/Moving\n-- Address Load Tokens
> Owns (effective) Host ID Rack\nUL 127.0.0.1
> 174.2 KiB 32 78.4%
> b8c55c71-bf3d-462b-8c17-3c88d7ac2284 rack1\nUN 127.0.0.2 370.04 KiB 32
> 65.9% 71aacf1d-8e2f-44cf-b354-f10c71313ec6 rack1\nUN
> 127.0.0.3 116.7 KiB 32 55.7%
> 3a4529a3-dc7f-445c-aec3-94417c920fdf rack1\n\n\ndtest: DEBUG: removing ccm
> cluster test at: d:\\temp\\dtest-ce_wos\ndtest: DEBUG: clearing ssl stores
> from [d:\\temp\\dtest-ce_wos] directory\n--------------------- >> end
> captured logging << ---------------------"
> Standard Output
> Unexpected error in node1 log, error:
> ERROR [StreamConnectionEstablisher:1] 2016-04-04 21:20:13,361
> StreamSession.java:519 - [Stream #df460340-faaa-11e5-a489-9fa05b8758d9]
> Streaming error occurred on session with peer 127.0.0.2
> java.net.ConnectException: Connection refused: connect
> at sun.nio.ch.Net.connect0(Native Method) ~[na:1.8.0_51]
> at sun.nio.ch.Net.connect(Net.java:458) ~[na:1.8.0_51]
> at sun.nio.ch.Net.connect(Net.java:450) ~[na:1.8.0_51]
> at sun.nio.ch.SocketChannelImpl.connect(SocketChannelImpl.java:648)
> ~[na:1.8.0_51]
> at
> org.apache.cassandra.net.OutboundTcpConnectionPool.newSocket(OutboundTcpConnectionPool.java:141)
> ~[main/:na]
> at
> org.apache.cassandra.streaming.DefaultConnectionFactory.createConnection(DefaultConnectionFactory.java:52)
> ~[main/:na]
> at
> org.apache.cassandra.streaming.StreamSession.createConnection(StreamSession.java:253)
> ~[main/:na]
> at
> org.apache.cassandra.streaming.ConnectionHandler.initiate(ConnectionHandler.java:83)
> ~[main/:na]
> at
> org.apache.cassandra.streaming.StreamSession.start(StreamSession.java:240)
> ~[main/:na]
> at
> org.apache.cassandra.streaming.StreamCoordinator$StreamSessionConnector.run(StreamCoordinator.java:263)
> [main/:na]
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> [na:1.8.0_51]
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> [na:1.8.0_51]
> at java.lang.Thread.run(Thread.java:745) [na:1.8.0_51]
> Standard Error
> Started: node1 with pid: 7740
> Started: node3 with pid: 7796
> Started: node2 with pid: 128
> Started: node2 with pid: 4088
> Started: node2 with pid: 6116
> Started: node2 with pid: 5168
> Started: node2 with pid: 1908
> Started: node2 with pid: 4436
> {code}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
