[ https://issues.apache.org/jira/browse/CASSANDRA-11611?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Philip Thompson updated CASSANDRA-11611: ---------------------------------------- Fix Version/s: (was: 3.x) Status: Patch Available (was: Open) > 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: Paulo Motta > Labels: dtest > > 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)